Frp: 实际测试 frps 心跳超时大约 30s

[ethsonliu]

frpc 和 frps 版本都是 0.27.0，运行环境：客户端 arm x86；服务端 ubuntu 14.04 x64。

# frps.ini
[common]
bind_port = 7000
vhost_http_port = 8080
subdomain_host = example.com

dashboard_port = 7500
dashboard_user = admin
dashboard_pwd = admin

# frpc.ini
[common]
server_addr=example.com
server_port=7000
tls_enable=true

[web123456]
type=http
local_ip=127.0.0.1
local_port=80
subdomain=123456

测试过程：

1. 启动 frps
2. 启动 frpc，可以观察到 frps 日志显示客户端上线
3. 在观察到 frps 日志显示客户端上线后，立马关闭 frpc 网络，等待 frps 打印客户端离线日志，并记录本次步骤的时长
4. 重复步骤 2,3

测试结果：

以下为 frps 端的日志打印，

root@qyi-5cd769af7bff4:/home# ./frps -c ./frps.ini 
2019/08/07 09:52:07 [I] [service.go:139] frps tcp listen on 0.0.0.0:7000
2019/08/07 09:52:07 [I] [service.go:181] http service listen on 0.0.0.0:8080
2019/08/07 09:52:07 [I] [service.go:232] Dashboard listen on 0.0.0.0:7500
2019/08/07 09:52:07 [I] [root.go:204] Start frps success

# 测试 1
2019/08/07 09:52:24 [I] [service.go:340] client login info: ip [183.250.162.103:61313] version [0.27.0] hostname [] os [linux] arch [arm]
2019/08/07 09:52:24 [I] [http.go:90] [5f8d78bef3497eab] [web123456] http proxy listen for host [123456.liuyir.com] location []
2019/08/07 09:52:24 [I] [control.go:426] [5f8d78bef3497eab] new proxy [web123456] success
2019/08/07 09:52:54 [I] [control.go:301] [5f8d78bef3497eab] control writer is closing
2019/08/07 09:52:54 [I] [proxy.go:82] [5f8d78bef3497eab] [web123456] proxy closing
2019/08/07 09:52:54 [I] [proxy.go:83] [5f8d78bef3497eab] [web123456] my find name [web123456]
2019/08/07 09:52:54 [I] [control.go:377] [5f8d78bef3497eab] client exit success

# 测试 2
2019/08/07 09:53:04 [I] [service.go:340] client login info: ip [183.250.162.101:8129] version [0.27.0] hostname [] os [linux] arch [arm]
2019/08/07 09:53:05 [I] [http.go:90] [5f8d78bef3497eab] [web123456] http proxy listen for host [123456.liuyir.com] location []
2019/08/07 09:53:05 [I] [control.go:426] [5f8d78bef3497eab] new proxy [web123456] success
2019/08/07 09:53:34 [I] [control.go:301] [5f8d78bef3497eab] control writer is closing
2019/08/07 09:53:34 [I] [proxy.go:82] [5f8d78bef3497eab] [web123456] proxy closing
2019/08/07 09:53:34 [I] [control.go:377] [5f8d78bef3497eab] client exit success

# 测试 3
2019/08/07 09:53:44 [I] [service.go:340] client login info: ip [183.250.162.102:49505] version [0.27.0] hostname [] os [linux] arch [arm]
2019/08/07 09:53:44 [I] [http.go:90] [5f8d78bef3497eab] [web123456] http proxy listen for host [123456.liuyir.com] location []
2019/08/07 09:53:44 [I] [control.go:426] [5f8d78bef3497eab] new proxy [web123456] success
2019/08/07 09:54:14 [I] [control.go:301] [5f8d78bef3497eab] control writer is closing
2019/08/07 09:54:14 [I] [proxy.go:82] [5f8d78bef3497eab] [web123456] proxy closing
2019/08/07 09:54:14 [I] [control.go:377] [5f8d78bef3497eab] client exit success

# 测试 4
2019/08/07 09:54:19 [I] [service.go:340] client login info: ip [183.250.162.102:56769] version [0.27.0] hostname [] os [linux] arch [arm]
2019/08/07 09:54:19 [I] [http.go:90] [5f8d78bef3497eab] [web123456] http proxy listen for host [123456.liuyir.com] location []
2019/08/07 09:54:19 [I] [control.go:426] [5f8d78bef3497eab] new proxy [web123456] success
2019/08/07 09:54:49 [I] [control.go:301] [5f8d78bef3497eab] control writer is closing
2019/08/07 09:54:49 [I] [proxy.go:82] [5f8d78bef3497eab] [web123456] proxy closing
2019/08/07 09:54:49 [I] [control.go:377] [5f8d78bef3497eab] client exit success

# 测试 5
2019/08/07 09:54:54 [I] [service.go:340] client login info: ip [183.250.162.102:6625] version [0.27.0] hostname [] os [linux] arch [arm]
2019/08/07 09:54:55 [I] [http.go:90] [5f8d78bef3497eab] [web123456] http proxy listen for host [123456.liuyir.com] location []
2019/08/07 09:54:55 [I] [control.go:426] [5f8d78bef3497eab] new proxy [web123456] success
2019/08/07 09:55:24 [I] [control.go:301] [5f8d78bef3497eab] control writer is closing
2019/08/07 09:55:24 [I] [proxy.go:82] [5f8d78bef3497eab] [web123456] proxy closing
2019/08/07 09:55:24 [I] [control.go:377] [5f8d78bef3497eab] client exit success

一共五次测试，显示结果心跳超时大约为 30s。

我的问题：

我源码跟踪，看到服务端确实是默认 90s 的心跳超时，但是实际测试的结果是 30s。是我的测试有问题？还是代码有别的处理，真实的超时就是 30s？

[fatedier]

调试时日志级别设置为 trace，可以打印更详细的信息。

[fatedier]

日志里面没有 heartbeat timeout ，所以并不是因为心跳超时而断开。

[ethsonliu]

@fatedier 服务端开启log_level=trace后，多加了条输出，

2019/08/07 13:57:21 [D] [service.go:325] Accept new mux stream error: keepalive timeout

keepalive-timeout 和 heartbeat-timeout 有什么区别，具体是分别想用来干嘛的？

按我的理解，不都是用来判断客户端是否断掉的嘛，如果超时了，就关闭与客户端的连接，节省服务端资源。如果我的理解没错，那为什么弄两个超时呢？

[fatedier]

这个是底层多路复用协议的超时时间，目前确实是 30s。

[ethsonliu]

@fatedier 也就是说，即使在 frps.ini 修改了心跳超时时长，但是大于 30s，实际上是没有作用的，只有小于 30s，才会起作用，我的理解对么？

[fatedier]

不完全对，看在什么样的场景下，一个是类似于 TCP 这一层的超时，一个是上层应用层的超时。

[ethsonliu]

嗯，好的，谢谢。