mirror of
https://github.com/fatedier/frp.git
synced 2026-05-15 16:15:49 -06:00
[GH-ISSUE #823] frps到frpc连接断开，不能再恢复连接。client error message: reconnect to server error: i/o deadline reached #644
Labels
No labels
In Progress
WIP
WaitingForInfo
bug
doc
duplicate
easy
enhancement
future
help wanted
invalid
lifecycle/stale
need-issue-template
need-usage-help
no plan
proposal
pull-request
question
todo
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference: github-starred/frp#644
Loading…
Add table
Add a link
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Originally created by @ghcoba on GitHub (Jun 11, 2018).
Original GitHub issue: https://github.com/fatedier/frp/issues/823
现象：
运行过程中出现frps到frpc的连接断开，frpc在frps上启动的全部连接断开并一直处于offline状态。frps无法再访问frpc。
client端log显示：reconnect to server error: i/o deadline reached.
（dashboard可访问，dashboard中显示与client的连接为断开， client为offline。）
在客户端热重载配置后，可恢复frps到frpc的连接。
frpc 客户端 enviroment:
版本
version
$ ./frpc -v
0.20.0
操作系统
os
$ uname -a
FreeBSD st05 11.1-RELEASE-p10 FreeBSD 11.1-RELEASE-p10 #0: Tue May 8 05:21:56 UTC 2018
root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC amd64
(ref:
frps 服务器端
版本
$ frps -v
0.20.0
操作系统
$ uname -a
Linux ss.xxxxx.xxx 2.6.32-042stab124.2 #1 SMP Fri Sep 1 20:42:18 MSK 2017 x86_64 x86_64 x86_64 GNU/Linux
)
配置（frpc）
Configures you used:
frpc.ini
[common]
server_addr = 210.16.xxx.xx
server_port = 7000
protocol = kcp
admin_addr = 127.0.0.1
admin_port = 7400
log_file = /etc/frp/frpc.log
log_level = info
log_max_days = 3
pool_count = 5
tcp_mux = true
login_fail_exit = false
[ssh]
type = tcp
local_ip = 127.0.0.1
local_port = 22
remote_port = 6000
use_encryption = false
use_compression = true
[cloud]
privilege_mode = true
type = http
local_port = 4080
remote_port = 80
custom_domains = cloud.xxxxx.xxx
use_encryption = false
use_compression = true
[p2p_ssh]
type = xtcp
local_ip = 127.0.0.1
local_port = 22
[svr_http_proxy]
type = tcp
remote_port = 3080
plugin = http_proxy
------------------ end of frpc.ini
配置（frps）
frps.ini
[common]
bind_addr = 0.0.0.0
bind_port = 7000
kcp_bind_port = 7000
bind_udp_port = 7001
vhost_http_port = 4080
vhost_https_port = 8443
dashboard_addr = 0.0.0.0
dashboard_port = 7500
dashboard_user = admin
dashboard_pwd = adminxxxxx
log_file = /etc/frp/frps.log
log_level = info
log_max_days = 3
privilege_mode = true
allow_ports = 25,110,143,443,465,993,995,3080,3081,4000-90000
heartbeat_timeout = 30
max_pool_count = 50
max_ports_per_client = 0
authentication_timeout = 0
tcp_mux = true
------------------ end of frps.ini
frpc.log - error occured @ 00:41:09
2018/06/12 00:00:16 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:00:26 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:00:46 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:00:49 [I] [control.go:246] [664b8e81b1bcf16b] login to server success, get run id [66$
2018/06/12 00:00:49 [I] [control.go:169] [664b8e81b1bcf16b] [ssh] start proxy success
2018/06/12 00:00:49 [I] [control.go:169] [664b8e81b1bcf16b] [cloud] start proxy success
2018/06/12 00:00:49 [I] [control.go:169] [664b8e81b1bcf16b] [p2p_ssh] start proxy success
2018/06/12 00:00:49 [I] [control.go:169] [664b8e81b1bcf16b] [svr_http_proxy] start proxy success
2018/06/12 00:28:06 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:28:06 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:28:06 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:28:06 [I] [control.go:308] [664b8e81b1bcf16b] control writer is closing
2018/06/12 00:28:06 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:28:06 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:28:06 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:28:16 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:28:17 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:28:27 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:28:29 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:28:39 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
....
2018/06/12 00:30:27 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:30:37 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:30:57 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:30:57 [I] [control.go:246] [664b8e81b1bcf16b] login to server success, get run id [66$
2018/06/12 00:30:57 [I] [control.go:169] [664b8e81b1bcf16b] [cloud] start proxy success
2018/06/12 00:30:57 [I] [control.go:169] [664b8e81b1bcf16b] [p2p_ssh] start proxy success
2018/06/12 00:30:57 [I] [control.go:169] [664b8e81b1bcf16b] [svr_http_proxy] start proxy success
2018/06/12 00:30:57 [I] [control.go:169] [664b8e81b1bcf16b] [ssh] start proxy success
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:09 [I] [control.go:308] [664b8e81b1bcf16b] control writer is closing
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:09 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:09 [E] [control.go:152] [664b8e81b1bcf16b] work connection closed, EOF
2018/06/12 00:41:19 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:41:20 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:41:30 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:41:32 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:41:42 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:41:46 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:41:56 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:42:04 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:42:14 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
......
2018/06/12 00:54:11 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:54:31 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:54:41 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:55:01 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:55:11 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:55:31 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:55:41 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
2018/06/12 00:56:01 [I] [control.go:407] [664b8e81b1bcf16b] try to reconnect to server...
2018/06/12 00:56:11 [W] [control.go:410] [664b8e81b1bcf16b] reconnect to server error: i/o deadline$
---- end frpc.log
frps.log
2018/06/12 00:40:31 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:40:36 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:40:37 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:40:41 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:40:45 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:41:01 [I] [proxy.go:87] [664b8e81b1bcf16b] [cloud] get a new work connection: [120.22$
2018/06/12 00:41:09 [I] [control.go:220] [664b8e81b1bcf16b] control writer is closing
2018/06/12 00:41:09 [I] [proxy.go:73] [664b8e81b1bcf16b] [svr_http_proxy] proxy closing
2018/06/12 00:41:09 [I] [proxy.go:73] [664b8e81b1bcf16b] [ssh] proxy closing
2018/06/12 00:41:09 [I] [proxy.go:73] [664b8e81b1bcf16b] [cloud] proxy closing
2018/06/12 00:41:09 [I] [proxy.go:73] [664b8e81b1bcf16b] [p2p_ssh] proxy closing
2018/06/12 00:41:09 [I] [control.go:292] [664b8e81b1bcf16b] client exit success
2018/06/12 00:41:09 [I] [proxy.go:119] [664b8e81b1bcf16b] [ssh] listener is closed
2018/06/12 00:41:09 [W] [newhttp.go:202] http: proxy error: EOF
2018/06/12 00:41:09 [I] [proxy.go:119] [664b8e81b1bcf16b] [svr_http_proxy] listener is closed
2018/06/12 00:41:09 [W] [newhttp.go:202] http: proxy error: EOF
2018/06/12 00:41:29 [W] [newhttp.go:202] http: proxy error: no such domain
2018/06/12 00:41:30 [W] [newhttp.go:202] http: proxy error: no such domain
2018/06/12 00:41:35 [W] [newhttp.go:202] http: proxy error: no such domain
2018/06/12 00:41:48 [W] [newhttp.go:202] http: proxy error: no such domain
2018/06/12 00:43:51 [I] [dashboard_api.go:67] Http request: [/api/serverinfo]
2018/06/12 00:43:51 [I] [dashboard_api.go:64] Http response [/api/serverinfo]: code [0]
2018/06/12 00:43:59 [I] [dashboard_api.go:178] Http request: [/api/proxy/tcp]
2018/06/12 00:43:59 [I] [dashboard_api.go:174] Http response [/api/proxy/tcp]: code [0]
2018/06/12 00:43:59 [I] [dashboard_api.go:175] /api/proxy/tcp
2018/06/12 00:43:59 [I] [dashboard_api.go:176]
2018/06/12 00:49:50 [I] [dashboard_api.go:178] Http request: [/api/proxy/tcp]
2018/06/12 00:49:50 [I] [dashboard_api.go:174] Http response [/api/proxy/tcp]: code [0]
2018/06/12 00:49:50 [I] [dashboard_api.go:175] /api/proxy/tcp
2018/06/12 00:49:50 [I] [dashboard_api.go:176]
--- end frps.log
dashboard message about error:
Name cloud
Type http
Domains[ "cloud.xxxx.xxx" ]
SubDomain locations[ "" ]
Host Rewrite
Encryption false
Compression true
Last Start06-12 00:58:01 (在客户端进行热重载配置后重新启动的连接)
Last Close06-12 00:41:09 （发生错误的时间。 连接断开。从服务器端无法访问frpc端）
--- end dashboard message
Steps to reproduce the issue:
有时会出现连接断开，无法再从服务器端访问到frpc。
（但是可以访问服务端的dashboard，dashboard显示与client的连接为断开， client为offline。）
Describe the results you received:
运行过程中出现frps到frpc的连接断开，frpc在frps上启动的全部连接断开并一直处于offline状态。frps无法再访问frpc。
client端log显示：reconnect to server error: i/o deadline reached.
在客户端热重载配置后，可恢复frps到frpc的连接。
注：在客户端重启frpc后，可以建立连接，恢复从服务器端访问客户端。 （使用 frpc reload -c ./frpc.ini）
Describe the results you expected:
(预期正确的结果为不出现frps到frpc的连接断开的情况)
Additional information you deem important (e.g. issue happens only occasionally):
( 此故障有时出现，不出现问题时很长时间都工作正常。未发现重现此故障的方法。
相关配置：
)
Can you point out what caused this issue (optional)
(可能是frpc端的问题。热重载frpc.ini配置后可恢复工作（frps端不做处理的情况下）)
@fatedier commented on GitHub (Jun 12, 2018):
重连超时了，还是检查下网络环境了，网络问题可能比较复杂。
@ghcoba commented on GitHub (Jun 13, 2018):
在trace记录中一直会出现“join connections closed”，这个是程序在作什么动作？
--- frpc.log (log_level = trace ) --
2018/06/13 22:03:34 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:03:34 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:47587] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:03:34 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:03:35 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:03:35 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:23955] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:03:35 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:03:36 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:03:36 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:43938] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:03:36 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:03:56 [D] [control.go:340] [e8d56b95b222c004] send heartbeat to server
2018/06/13 22:03:56 [D] [control.go:361] [e8d56b95b222c004] receive heartbeat from server
2018/06/13 22:04:02 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:04:02 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:56835] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:04:02 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:04:26 [D] [control.go:340] [e8d56b95b222c004] send heartbeat to server
2018/06/13 22:04:26 [D] [control.go:361] [e8d56b95b222c004] receive heartbeat from server
2018/06/13 22:04:28 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:04:28 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:59070] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:04:28 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:04:56 [D] [control.go:340] [e8d56b95b222c004] send heartbeat to server
2018/06/13 22:04:56 [D] [control.go:361] [e8d56b95b222c004] receive heartbeat from server
2018/06/13 22:04:58 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:04:58 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:25133] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:04:58 [D] [proxy.go:453] [cloud] join connections closed
2018/06/13 22:05:26 [D] [control.go:340] [e8d56b95b222c004] send heartbeat to server
2018/06/13 22:05:26 [D] [control.go:361] [e8d56b95b222c004] receive heartbeat from server
2018/06/13 22:05:28 [D] [proxy_manager.go:135] [cloud] start a new work connection, localAddr: 10.0.0.9:58981 remoteAddr: 210.16.120.37:70$
2018/06/13 22:05:28 [D] [proxy.go:450] [cloud] join connections, localConn(l[127.0.0.1:44651] r[127.0.0.1:4080]) workConn(l[10.0.0.9:58981$
2018/06/13 22:05:28 [D] [proxy.go:453] [cloud] join connections closed
@ghcoba commented on GitHub (Jun 13, 2018):
(re-open)
@fatedier commented on GitHub (Jun 13, 2018):
这个从内容中应该就能看出来，记录了每一次 frpc 相关连接的建立和断开。
@ghcoba commented on GitHub (Jun 14, 2018):
谢谢。 我再观察一段时间网络情况。
我先关闭这个issue。
@lin2code commented on GitHub (Oct 19, 2018):
你是用的腾讯云吗
我也是这样，不定时会有几分钟连不上。
用阿里云一晚上都稳的，腾讯云出现两次大概
@john-shine commented on GitHub (Aug 22, 2019):
看是不是路由器开启了透明代理
@RayXu14 commented on GitHub (Nov 10, 2019):
请问什么是热重载配置
@marcuswang6 commented on GitHub (Mar 17, 2022):
同有这个问题，用的是腾讯云
报错信息：
control writer is closing
proxy closing
listener is closed: accept tcp [::]:6000: use of closed network connection
client exit success
@WangONC commented on GitHub (Feb 8, 2023):
我用腾讯云香港也不稳，加密tls啥的开了都没用，不知道是啥什么原因
@Satan023 commented on GitHub (May 14, 2023):
这两天轻量云香港也出现类似问题 经常重连
@MaelWeb commented on GitHub (Jun 7, 2023):
同 轻量云香港 ，重连还连不上。
还不定时 gracefully shutdown visitor manager
@Crazyokd commented on GitHub (Nov 9, 2023):
我的阿里云今天也遇到这种问题了，昨天还一切正常。