mirror of
https://github.com/fatedier/frp.git
synced 2026-05-15 08:05:49 -06:00
[GH-ISSUE #2898] 客户端不定时会突然失联, 经常能在15分钟左右后自动恢复, 如何解决? 或减少自动恢复的时间 #2309
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#2309
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 @zhangjf-autoxing on GitHub (Apr 18, 2022).
Original GitHub issue: https://github.com/fatedier/frp/issues/2898
Bug Description
客户端不定时会突然失联, 经常能在15分钟左右后自动恢复, 如何解决? 或减少自动恢复的时间
frpc Version
0.38.0
frps Version
0.38.0
System Architecture
frps: linux/amd64 ; frpc: linux/aarch64(arm64)
Configurations
frps.ini
[common]
bind_port = 7002
dashboard_port = 7502
dashboard_user = admin
dashboard_pwd = ********
tls_only = true
tls_enable = true
tls_cert_file = /pathto/server.crt
tls_key_file = /pathto/server.key
tls_trusted_ca_file = /pathto/ca.crt
allow_ports = 10001-29999
log_file = /pathto/frps.log
log_level = info
log_max_days = 365
authentication_method = token
token = ******
tcp_mux = false
kcp_bind_port = 7002
###frpc.ini
[common]
tcp_mux = false
server_addr = xxx.xxx.com
server_port = 7002
token = ******
tls_enable = true
tls_cert_file = /pathto/server.crt
tls_key_file = /pathto/server.key
tls_trusted_ca_file = /pathto/ca.crt
[xxx-ssh]
type = tcp
local_ip = 127.0.0.1
local_port = 22
remote_port = 10157
[xxx-http]
type = tcp
local_ip = 127.0.0.1
local_port = 8000
remote_port = 10158
Logs
以下典型日志, 是一个15分钟后自动恢复的样例, 大概在12:26:32断开, 13:41:17恢复
日志中部分信息做了混淆
sudo journalctl -u frpc
-- Logs begin at Mon 2022-04-18 11:17:01 CST, end at Mon 2022-04-18 14:22:54 CST. --
Apr 18 11:17:10 71822011000160g systemd[1]: Started Frp Client Service.
Apr 18 11:17:10 71822011000160g frpc[594]: 2022/04/18 11:17:10 [I] [service.go:301] [e37e3e2243c12e58] login to server success, get run id [e37e3e2243c12e58], server udp port [0]
Apr 18 11:17:10 71822011000160g frpc[594]: 2022/04/18 11:17:10 [I] [proxy_manager.go:144] [e37e3e2243c12e58] proxy added: [-ssh -http]
Apr 18 11:17:11 71822011000160g frpc[594]: 2022/04/18 11:17:11 [I] [control.go:180] [e37e3e2243c12e58] [-ssh] start proxy success
Apr 18 11:17:11 71822011000160g frpc[594]: 2022/04/18 11:17:11 [I] [control.go:180] [e37e3e2243c12e58] [-http] start proxy success
Apr 18 12:22:26 71822011000160g frpc[594]: 2022/04/18 12:22:26 [E] [proxy.go:796] [e37e3e2243c12e58] [-http] connect to local service [127.0.0.1:8000] error: dial tcp 127.0.0.1:8000:
Apr 18 12:22:35 71822011000160g frpc[594]: 2022/04/18 12:22:35 [E] [proxy.go:796] [e37e3e2243c12e58] [-http] connect to local service [127.0.0.1:8000] error: dial tcp 127.0.0.1:8000:
Apr 18 12:26:32 71822011000160g frpc[594]: 2022/04/18 12:26:32 [W] [control.go:331] [e37e3e2243c12e58] heartbeat timeout
Apr 18 12:26:32 71822011000160g frpc[594]: 2022/04/18 12:26:32 [W] [control.go:268] [e37e3e2243c12e58] read error: read tcp 192.168.225.58:51390->**111.111.111.111:7002: use of closed network connection
Apr 18 12:26:32 71822011000160g frpc[594]: 2022/04/18 12:26:32 [I] [control.go:289] [e37e3e2243c12e58] control writer is closing
Apr 18 12:26:32 71822011000160g frpc[594]: 2022/04/18 12:26:32 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 12:26:32 71822011000160g frpc[594]: 2022/04/18 12:26:32 [I] [visitor_manager.go:60] [e37e3e2243c12e58] gracefully shutdown visitor manager
Apr 18 12:27:41 71822011000160g frpc[594]: 2022/04/18 12:27:41 [E] [control.go:158] [e37e3e2243c12e58] work connection closed before response StartWorkConn message: read tcp 192.168.225.58:53764->111.111.111.111
Apr 18 12:28:52 71822011000160g frpc[594]: 2022/04/18 12:28:52 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp 111.111.111.111:7002: connect: connection timed out
Apr 18 12:28:53 71822011000160g frpc[594]: 2022/04/18 12:28:53 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 12:29:00 71822011000160g frpc[594]: 2022/04/18 12:29:00 [I] [service.go:301] [e37e3e2243c12e58] login to server success, get run id [e37e3e2243c12e58], server udp port [0]
Apr 18 12:29:00 71822011000160g frpc[594]: 2022/04/18 12:29:00 [I] [proxy_manager.go:144] [e37e3e2243c12e58] proxy added: [-ssh -http]
Apr 18 12:29:00 71822011000160g frpc[594]: 2022/04/18 12:29:00 [I] [control.go:180] [e37e3e2243c12e58] [-ssh] start proxy success
Apr 18 12:29:00 71822011000160g frpc[594]: 2022/04/18 12:29:00 [I] [control.go:180] [e37e3e2243c12e58] [-http] start proxy success
Apr 18 13:39:01 71822011000160g frpc[594]: 2022/04/18 13:39:01 [W] [control.go:331] [e37e3e2243c12e58] heartbeat timeout
Apr 18 13:39:01 71822011000160g frpc[594]: 2022/04/18 13:39:01 [W] [control.go:268] [e37e3e2243c12e58] read error: read tcp 192.168.225.58:53906->**111.111.111.111:7002: use of closed network connection
Apr 18 13:39:01 71822011000160g frpc[594]: 2022/04/18 13:39:01 [I] [control.go:289] [e37e3e2243c12e58] control writer is closing
Apr 18 13:39:01 71822011000160g frpc[594]: 2022/04/18 13:39:01 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:39:01 71822011000160g frpc[594]: 2022/04/18 13:39:01 [I] [visitor_manager.go:60] [e37e3e2243c12e58] gracefully shutdown visitor manager
Apr 18 13:39:11 71822011000160g frpc[594]: 2022/04/18 13:39:11 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:58080->
Apr 18 13:39:12 71822011000160g frpc[594]: 2022/04/18 13:39:12 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:39:22 71822011000160g frpc[594]: 2022/04/18 13:39:22 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:44470->
Apr 18 13:39:24 71822011000160g frpc[594]: 2022/04/18 13:39:24 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:39:34 71822011000160g frpc[594]: 2022/04/18 13:39:34 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:40990->
Apr 18 13:39:36 71822011000160g frpc[594]: 2022/04/18 13:39:36 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:39:46 71822011000160g frpc[594]: 2022/04/18 13:39:46 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:54905->
Apr 18 13:39:48 71822011000160g frpc[594]: 2022/04/18 13:39:48 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:39:58 71822011000160g frpc[594]: 2022/04/18 13:39:58 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:35587->
Apr 18 13:40:00 71822011000160g frpc[594]: 2022/04/18 13:40:00 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:40:10 71822011000160g frpc[594]: 2022/04/18 13:40:10 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:55566->
Apr 18 13:40:12 71822011000160g frpc[594]: 2022/04/18 13:40:12 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:40:18 71822011000160g frpc[594]: 2022/04/18 13:40:18 [E] [control.go:158] [e37e3e2243c12e58] work connection closed before response StartWorkConn message: read tcp 192.168.225.58:54484->**111.111.111.111
Apr 18 13:40:18 71822011000160g frpc[594]: 2022/04/18 13:40:18 [E] [control.go:158] [e37e3e2243c12e58] work connection closed before response StartWorkConn message: read tcp 192.168.225.58:54474->**111.111.111.111
Apr 18 13:40:22 71822011000160g frpc[594]: 2022/04/18 13:40:22 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:36462->
Apr 18 13:40:23 71822011000160g frpc[594]: 2022/04/18 13:40:23 [E] [control.go:158] [e37e3e2243c12e58] work connection closed before response StartWorkConn message: read tcp 192.168.225.58:54518->**111.111.111.111
Apr 18 13:40:24 71822011000160g frpc[594]: 2022/04/18 13:40:24 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:40:34 71822011000160g frpc[594]: 2022/04/18 13:40:34 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:37521->
Apr 18 13:40:36 71822011000160g frpc[594]: 2022/04/18 13:40:36 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:40:46 71822011000160g frpc[594]: 2022/04/18 13:40:46 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:37818->
Apr 18 13:40:48 71822011000160g frpc[594]: 2022/04/18 13:40:48 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:40:58 71822011000160g frpc[594]: 2022/04/18 13:40:58 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup **xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:41017->
Apr 18 13:41:00 71822011000160g frpc[594]: 2022/04/18 13:41:00 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:41:10 71822011000160g frpc[594]: 2022/04/18 13:41:10 [W] [service.go:177] [e37e3e2243c12e58] reconnect to server error: dial tcp: lookup xxx.xxx.com on 127.0.0.1:53: read udp 127.0.0.1:42524->
Apr 18 13:41:12 71822011000160g frpc[594]: 2022/04/18 13:41:12 [I] [service.go:174] [e37e3e2243c12e58] try to reconnect to server...
Apr 18 13:41:17 71822011000160g frpc[594]: 2022/04/18 13:41:17 [I] [service.go:301] [e37e3e2243c12e58] login to server success, get run id [e37e3e2243c12e58], server udp port [0]
Apr 18 13:41:17 71822011000160g frpc[594]: 2022/04/18 13:41:17 [I] [proxy_manager.go:144] [e37e3e2243c12e58] proxy added: [-http -ssh]
Apr 18 13:41:17 71822011000160g frpc[594]: 2022/04/18 13:41:17 [I] [control.go:180] [e37e3e2243c12e58] [-http] start proxy success
Steps to reproduce
...
Affected area
@fatedier commented on GitHub (Apr 18, 2022):
可能断网了，尝试更换网络环境。
@zhangjf-autoxing commented on GitHub (Apr 18, 2022):
感谢回复! 我们尝试换过, 仍然会不定时出现这个现象. 而且, 我们发现一个现象, 只要在失联时, 重启一下frpc服务, 就能立即连上服务端, 不用等15分钟了. 请问, 有相关参数可以优化调整吗?
@fatedier commented on GitHub (Apr 18, 2022):
没有，建议还是定位网络故障原因。
比如服务端和客户端部署在同一台机器上，观察是否有影响。
服务端和客户端部署在不同机器，但是同一个内网中，观察是否有影响。
@zhangjf-autoxing commented on GitHub (Apr 18, 2022):
非常感谢作者的及时回复
@Pancratius commented on GitHub (Jun 8, 2022):
@zhangjf-autoxing 排查到是什么原因了吗，我这边也遇到这个情况
@zhangjf-autoxing commented on GitHub (Jun 8, 2022):
没有进展 @Pancratius
@guol-fnst commented on GitHub (Sep 5, 2022):
把tcp_mux 关掉
@guol-fnst commented on GitHub (Sep 5, 2022):
把tcp_mux 关掉