mirror of
https://github.com/fatedier/frp.git
synced 2026-05-15 08:05:49 -06:00
[GH-ISSUE #1886] 反复 gracefully shutdown visitor manager? #1493
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#1493
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 @sshuangliu on GitHub (Jun 29, 2020).
Original GitHub issue: https://github.com/fatedier/frp/issues/1886
Originally assigned to: @blizard863 on GitHub.
[root@VM_0_2_centos frp_0.33.0_linux_386]# cat frps.ini
[common]
bind_port = 7109
kcp_bind_port = 7109
#dashboard_port = 7509
#dashboard_user = admin
#dashboard_pwd = xxxxoooo
log_file = /software_install/frp_0.33.0_linux_386/frps.log
log_level = debug
#for authentication
token = xxoo
pi@raspberrypi:/my_env001/frp_0.33.0_linux_arm$ cat frpc.ini
[common]
server_addr = x.x.x.x
server_port = 7109
protocol = kcp
log_file = /my_env001/frp_0.33.0_linux_arm/frpc.log
log_level = debug
admin_addr = 192.168.1.7
admin_port = 7400
admin_user = xxxx
admin_pwd = xxxx
#for authentication
token = xxoo
[secret_rdp]
type = stcp
sk = xxooxxoo
local_ip = 192.168.1.4
local_port = 3389
[ssh]
type = tcp
local_ip = 127.0.0.1
local_port = 22
remote_port = 2222
frpc.log:
2020/06/29 19:00:30 [I] [proxy_manager.go:144] [0313c34b4092cccc] proxy added: [secret_rdp ssh]
2020/06/29 19:00:30 [I] [control.go:179] [0313c34b4092cccc] [secret_rdp] start proxy success
2020/06/29 19:00:30 [I] [control.go:179] [0313c34b4092cccc] [ssh] start proxy success
2020/06/29 19:01:00 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:01:00 [D] [control.go:331] [0313c34b4092cccc] receive heartbeat from server
2020/06/29 19:01:30 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:01:40 [D] [control.go:242] [0313c34b4092cccc] read from control connection EOF
2020/06/29 19:01:40 [E] [control.go:157] [0313c34b4092cccc] work connection closed before response StartWorkConn message: EOF
2020/06/29 19:01:40 [I] [control.go:267] [0313c34b4092cccc] control writer is closing
2020/06/29 19:01:40 [I] [visitor_manager.go:60] [0313c34b4092cccc] gracefully shutdown visitor manager
2020/06/29 19:01:40 [I] [service.go:174] [0313c34b4092cccc] try to reconnect to server...
2020/06/29 19:01:46 [I] [service.go:282] [0313c34b4092cccc] login to server success, get run id [0313c34b4092cccc], server udp port [0]
2020/06/29 19:01:46 [I] [proxy_manager.go:144] [0313c34b4092cccc] proxy added: [secret_rdp ssh]
2020/06/29 19:01:46 [I] [control.go:179] [0313c34b4092cccc] [secret_rdp] start proxy success
2020/06/29 19:01:46 [I] [control.go:179] [0313c34b4092cccc] [ssh] start proxy success
2020/06/29 19:02:16 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:02:16 [D] [control.go:331] [0313c34b4092cccc] receive heartbeat from server
2020/06/29 19:02:46 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:02:50 [D] [control.go:242] [0313c34b4092cccc] read from control connection EOF
2020/06/29 19:02:50 [E] [control.go:157] [0313c34b4092cccc] work connection closed before response StartWorkConn message: EOF
2020/06/29 19:02:50 [I] [control.go:267] [0313c34b4092cccc] control writer is closing
2020/06/29 19:02:50 [I] [service.go:174] [0313c34b4092cccc] try to reconnect to server...
2020/06/29 19:02:50 [I] [visitor_manager.go:60] [0313c34b4092cccc] gracefully shutdown visitor manager
2020/06/29 19:02:56 [I] [service.go:282] [0313c34b4092cccc] login to server success, get run id [0313c34b4092cccc], server udp port [0]
2020/06/29 19:02:56 [I] [proxy_manager.go:144] [0313c34b4092cccc] proxy added: [secret_rdp ssh]
2020/06/29 19:02:56 [I] [control.go:179] [0313c34b4092cccc] [secret_rdp] start proxy success
2020/06/29 19:02:56 [I] [control.go:179] [0313c34b4092cccc] [ssh] start proxy success
2020/06/29 19:03:26 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:03:26 [D] [control.go:331] [0313c34b4092cccc] receive heartbeat from server
2020/06/29 19:03:56 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:04:01 [D] [control.go:242] [0313c34b4092cccc] read from control connection EOF
2020/06/29 19:04:01 [E] [control.go:157] [0313c34b4092cccc] work connection closed before response StartWorkConn message: EOF
2020/06/29 19:04:01 [I] [control.go:267] [0313c34b4092cccc] control writer is closing
2020/06/29 19:04:01 [I] [service.go:174] [0313c34b4092cccc] try to reconnect to server...
2020/06/29 19:04:01 [I] [visitor_manager.go:60] [0313c34b4092cccc] gracefully shutdown visitor manager
2020/06/29 19:04:01 [I] [service.go:282] [0313c34b4092cccc] login to server success, get run id [0313c34b4092cccc], server udp port [0]
2020/06/29 19:04:01 [I] [proxy_manager.go:144] [0313c34b4092cccc] proxy added: [secret_rdp ssh]
2020/06/29 19:04:01 [I] [control.go:179] [0313c34b4092cccc] [secret_rdp] start proxy success
2020/06/29 19:04:01 [I] [control.go:179] [0313c34b4092cccc] [ssh] start proxy success
2020/06/29 19:04:31 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:04:31 [D] [control.go:331] [0313c34b4092cccc] receive heartbeat from server
2020/06/29 19:05:01 [D] [control.go:300] [0313c34b4092cccc] send heartbeat to server
2020/06/29 19:05:01 [D] [control.go:331] [0313c34b4092cccc] receive heartbeat from server
frps.log:
2020/06/29 19:11:36 [I] [service.go:178] frps tcp listen on 0.0.0.0:7109
2020/06/29 19:11:36 [I] [service.go:187] frps kcp listen on udp 0.0.0.0:7109
2020/06/29 19:11:36 [I] [root.go:209] start frps success
2020/06/29 19:11:47 [W] [service.go:383] CheckAndEnableTLSServerConnWithTimeout error: timeout
2020/06/29 19:11:47 [I] [service.go:432] [0313c34b4092cccc] client login info: ip [114.88.242.197:44225] version [0.33.0] hostname [] os [linux] arch [arm]
2020/06/29 19:11:47 [D] [control.go:219] [0313c34b4092cccc] new work connection registered
2020/06/29 19:11:47 [I] [stcp.go:34] [0313c34b4092cccc] [secret_rdp] stcp proxy custom listen success
2020/06/29 19:11:47 [I] [control.go:445] [0313c34b4092cccc] new proxy [secret_rdp] success
2020/06/29 19:11:47 [I] [tcp.go:63] [0313c34b4092cccc] [ssh] tcp proxy listen port [2222]
2020/06/29 19:11:47 [I] [control.go:445] [0313c34b4092cccc] new proxy [ssh] success
[root@VM_0_2_centos frp_0.33.0_linux_386]# systemctl status frps
● frps.service - frp port forward server
Loaded: loaded (/usr/lib/systemd/system/frps.service; disabled; vendor preset: disabled)
Active: activating (auto-restart) (Result: exit-code) since Mon 2020-06-29 19:19:52 CST; 3s ago
Process: 13704 ExecStart=/software_install/frp_0.33.0_linux_386/frps -c /software_install/frp_0.33.0_linux_386/frps.ini (code=exited, status=2)
Main PID: 13704 (code=exited, status=2)
Jun 29 19:19:52 VM_0_2_centos systemd[1]: frps.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Jun 29 19:19:52 VM_0_2_centos systemd[1]: Unit frps.service entered failed state.
Jun 29 19:19:52 VM_0_2_centos systemd[1]: frps.service failed.
[root@VM_0_2_centos frp_0.33.0_linux_386]# systemctl status frps
● frps.service - frp port forward server
Loaded: loaded (/usr/lib/systemd/system/frps.service; disabled; vendor preset: disabled)
Active: active (running) since Mon 2020-06-29 19:19:57 CST; 15s ago
Main PID: 13914 (frps)
CGroup: /system.slice/frps.service
└─13914 /software_install/frp_0.33.0_linux_386/frps -c /software_install/frp_0.33.0_linux_386/frps.ini
Jun 29 19:19:57 VM_0_2_centos systemd[1]: frps.service holdoff time over, scheduling restart.
Jun 29 19:19:57 VM_0_2_centos systemd[1]: Started frp port forward server.
Jun 29 19:19:57 VM_0_2_centos systemd[1]: Starting frp port forward server...
[root@VM_0_2_centos frp_0.33.0_linux_386]#
@fatedier commented on GitHub (Jun 29, 2020):
测试下为什么客户端和服务端会断开连接。
@sshuangliu commented on GitHub (Jun 29, 2020):
加了KCP后就这样了,,今天以上是测试的结果,重启客户端 服务端服务的日志
你说的的测试是指?
@fatedier commented on GitHub (Jun 29, 2020):
所以你自己已经进行了一些测试定位问题了,可以继续通过类似的方法调试一下具体的问题。
@sshuangliu commented on GitHub (Jun 29, 2020):
把C/S 端 KCP的配置去除后,就一切都正常了:
2020/06/29 20:14:30 [I] [control.go:179] [828a0bde0571bfcb] [ssh] start proxy success
2020/06/29 20:14:30 [I] [control.go:179] [828a0bde0571bfcb] [secret_rdp] start proxy success
2020/06/29 20:15:00 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:15:00 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:15:30 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:15:30 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:16:00 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:16:00 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:16:30 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:16:30 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:17:00 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:17:00 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:17:30 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:17:30 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:18:00 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:18:00 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:18:30 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:18:30 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
2020/06/29 20:19:00 [D] [control.go:300] [828a0bde0571bfcb] send heartbeat to server
2020/06/29 20:19:00 [D] [control.go:331] [828a0bde0571bfcb] receive heartbeat from server
@sshuangliu commented on GitHub (Jun 29, 2020):
那就是KCP的问题吧?或者说是KCP在我这种配置的功能场景中不支持吗? 然后再细节的 我就没法定位了
frps.log日志中的: 这些关键字 有头绪吗?
CheckAndEnableTLSServerConnWithTimeout error: timeout
[root@VM_0_2_centos frp_0.33.0_linux_386]# systemctl status frps
● frps.service - frp port forward server
Loaded: loaded (/usr/lib/systemd/system/frps.service; disabled; vendor preset: disabled)
Active: activating (auto-restart) (Result: exit-code) since Mon 2020-06-29 19:19:52 CST; 3s ago
Process: 13704 ExecStart=/software_install/frp_0.33.0_linux_386/frps -c /software_install/frp_0.33.0_linux_386/frps.ini (code=exited, status=2)
Main PID: 13704 (code=exited, status=2)
Jun 29 19:19:52 VM_0_2_centos systemd[1]: frps.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Jun 29 19:19:52 VM_0_2_centos systemd[1]: Unit frps.service entered failed state.
Jun 29 19:19:52 VM_0_2_centos systemd[1]: frps.service failed.
[root@VM_0_2_centos frp_0.33.0_linux_386]# systemctl status frps
● frps.service - frp port forward server
Loaded: loaded (/usr/lib/systemd/system/frps.service; disabled; vendor preset: disabled)
Active: active (running) since Mon 2020-06-29 19:19:57 CST; 15s ago
Main PID: 13914 (frps)
CGroup: /system.slice/frps.service
└─13914 /software_install/frp_0.33.0_linux_386/frps -c /software_install/frp_0.33.0_linux_386/frps.ini
Jun 29 19:19:57 VM_0_2_centos systemd[1]: frps.service holdoff time over, scheduling restart.
Jun 29 19:19:57 VM_0_2_centos systemd[1]: Started frp port forward server.
Jun 29 19:19:57 VM_0_2_centos systemd[1]: Starting frp port forward server...
[root@VM_0_2_centos frp_0.33.0_linux_386]#
@tommy110 commented on GitHub (Jul 1, 2020):
我这边也出现这样的问题,没有使用KCP,仅仅普通的TCP。
2020/07/01 16:22:11 [E] [control.go:157] [1edca75218c7640c] work connection closed before response StartWorkConn message: EOF
2020/07/01 16:22:11 [I] [control.go:267] [1edca75218c7640c] control writer is closing
2020/07/01 16:22:11 [I] [service.go:174] [1edca75218c7640c] try to reconnect to server...
2020/07/01 16:22:11 [I] [visitor_manager.go:60] [1edca75218c7640c] gracefully shutdown visitor manager
2020/07/01 16:22:11 [I] [service.go:282] [1edca75218c7640c] login to server success, get run id [1edca75218c7640c], server udp port [0]
@blizard863 commented on GitHub (Sep 15, 2020):
这种情况可以看下是否有防火墙。 一般是设置了防火墙,建立了连接,然后连接被强行关闭了,然后 frpc 不停的重连。