Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

heartbeat问题:udp proxy 空闲时无法维持client与server之间的heartbeat,连接丢失 #209

Closed
goer99 opened this issue Jan 2, 2017 · 16 comments
Labels

Comments

@goer99
Copy link

goer99 commented Jan 2, 2017

当frp空闲时,client端和server端无法维持heartbeat,导致双方连接丢失。因此,每次需要使用frp时,必须先通过其他vpn连到内网重新启动frp的client端(其实frp客户端进程并没有死),重新连接上才可以,很不方便。这是什么原因呢?

server端log如下:

2017/01/01 00:01:31 [control.go:139] [E] ProxyName [abc], client heartbeat timeout
2017/01/01 00:01:31 [server.go:175] [I] ProxyName [abc], udp listener is closed
2017/01/01 00:01:31 [control.go:151] [W] ProxyName [abc], client connection is closed
2017/01/01 00:01:31 [control.go:112] [I] ProxyName [abc], I'm dead!
2017/01/01 00:01:31 [server.go:301] [W] ProxyName [abc], work connection for udp closed
2017/01/01 00:01:56 [control.go:344] [I] ProxyName [abc], start proxy success
2017/01/01 08:23:37 [control.go:147] [W] ProxyName [abc], client is dead!
2017/01/01 08:23:37 [control.go:112] [I] ProxyName [abc], I'm dead!
2017/01/01 08:23:37 [server.go:175] [I] ProxyName [abc], udp listener is closed
2017/01/01 08:23:40 [control.go:344] [I] ProxyName [abc], start proxy success

@fatedier
Copy link
Owner

fatedier commented Jan 3, 2017

heartbeat 超时之后 frpc 会自动重连,日志级别可以设置成 debug,然后观察重连是否成功。

@goer99
Copy link
Author

goer99 commented Jan 4, 2017

重连不成功,log如下:

2017/01/04 10:33:01 �[1;34m[main.go:109] [I] Start frpc success�[0m
2017/01/04 10:33:07 �[1;31m[control.go:189] [E] ProxyName [abc], start proxy error, ProxyName [abc], already in use�[0m
2017/01/04 10:33:07 �[1;31m[control.go:39] [E] ProxyName [abc], connect to server failed!�[0m
2017/01/04 10:33:07 �[1;33m[main.go:112] [W] All proxy exit!�[0m

说明:为了防止frpc进程被杀或消失,设置了每分钟的crontab任务重启frpc。

@fatedier
Copy link
Owner

fatedier commented Jan 4, 2017

重连的机制是这样的,客户端每隔 20s 发一次心跳,服务器端超过 90s 没有收到心跳就认为客户端网络连接断了,会删掉这个 proxy,在此之前的 90s,你重新连接的话,服务器不确定之前的连接是否中断,所以会拒绝同名的 proxy 连接。而 frpc 在第一次启动时,如果连接失败会直接退出进程。

客户端重连,会按照 2s, 4s, 8s, 16s 的延迟尝试重连,最高 1min,重连失败会一直继续尝试。

从你的日志来看,这个 frpc 进程是第一次启动,并且由于上一次的 proxy 还没有达到超时时间被删除,所以出现 already in use 的提示并直接退出。理论上 frpc 在网络断开后不会自己退出,并且在 90s 内可能会出现 already in use 的错误提示,但是之后仍然会重新连接上。所以在出现网络异常时不要重启 frpc,而是等待重连,下个版本中这个超时时间会改为可配置。

@goer99
Copy link
Author

goer99 commented Jan 4, 2017

感谢解答。有两点建议供参考:
1、能否在debug级别的日志中记录frpc和fprs的心跳收/发情况?
2、能否在debug级别的日志中记录frpc的重连情况?
这样可以提供更多用于debug的日志。

我已经取消了crontab的周期性任务,再观察frpc是否会重连成功。谢谢。

@fatedier
Copy link
Owner

fatedier commented Jan 4, 2017

你说的这两个情况在 debug 级别中都是有日志的。

大致如下:

2017/01/04 14:22:46 [control.go:212] [D] Send heartbeat to server
2017/01/04 14:22:46 [control.go:212] [D] Send heartbeat to server
2017/01/04 14:22:46 [control.go:212] [D] Send heartbeat to server
2017/01/04 14:22:46 [control.go:212] [D] Send heartbeat to server
2017/01/04 14:22:46 [control.go:101] [D] ProxyName [web2], receive heartbeat response
2017/01/04 14:22:46 [control.go:101] [D] ProxyName [2], receive heartbeat response
2017/01/04 14:22:46 [control.go:101] [D] ProxyName [web], receive heartbeat response
2017/01/04 14:22:46 [control.go:101] [D] ProxyName [1], receive heartbeat response
2017/01/04 14:23:28 [control.go:72] [I] ProxyName [web], try to reconnect to frps [127.0.0.1:7000]...
2017/01/04 14:23:28 [control.go:181] [D] ProxyName [web], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 14:23:28 [control.go:194] [I] ProxyName [web], connect to server [127.0.0.1:7000] success!
2017/01/04 14:23:28 [control.go:208] [I] Start to send heartbeat to frps
2017/01/04 14:23:28 [control.go:72] [I] ProxyName [web2], try to reconnect to frps [127.0.0.1:7000]...
2017/01/04 14:23:28 [control.go:72] [I] ProxyName [2], try to reconnect to frps [127.0.0.1:7000]...
2017/01/04 14:23:28 [control.go:72] [I] ProxyName [1], try to reconnect to frps [127.0.0.1:7000]...
2017/01/04 14:23:28 [control.go:181] [D] ProxyName [web2], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 14:23:28 [control.go:194] [I] ProxyName [web2], connect to server [127.0.0.1:7000] success!
2017/01/04 14:23:28 [control.go:208] [I] Start to send heartbeat to frps
2017/01/04 14:23:28 [control.go:181] [D] ProxyName [1], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 14:23:28 [control.go:194] [I] ProxyName [1], connect to server [127.0.0.1:7000] success!
2017/01/04 14:23:28 [control.go:208] [I] Start to send heartbeat to frps
2017/01/04 14:23:28 [control.go:181] [D] ProxyName [2], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 14:23:28 [control.go:194] [I] ProxyName [2], connect to server [127.0.0.1:7000] success!

@goer99
Copy link
Author

goer99 commented Jan 4, 2017

谢谢,修改了一下配置文件,debug log生效了。

我使用的是简化的配置文件x_min.ini,之前一直把log文件的设置加在简化配置文件的最后,这让程序认为这些设置是proxy的设置,而不是common的设置,因此debug log未生效。刚才把debug log设置挪到common设置区,就生效了。

@goer99
Copy link
Author

goer99 commented Jan 4, 2017

问题仍然存在:frpc启动连上frps之后,二者之间无数据传输,过一段时间,则frp服务不可用。

下面是log,分为两个部分:第一部分是frp服务不可用的log记录(frps和frpc);第二部分是frp服务可用的log记录(frps和frpc),请帮助分析解决,谢谢。


frp服务不可用的log

说明:下午16:45启动frps,16:52最后一次启动frpc,二者成功连接。frpc和frps连接后,一直没有使用frp服务,仅让frpc和frps保持连接。20:13分左右,使用frp服务,不成功。


frps.log

//下午16:45启动frps

2017/01/04 16:45:46 [control.go:344] [I] ProxyName [abc], start proxy success
2017/01/04 16:47:08 [main.go:194] [I] Start frps success
2017/01/04 16:47:08 [main.go:196] [I] PrivilegeMode is enabled, you should pay more attention to security issues
2017/01/04 16:47:22 [main.go:194] [I] Start frps success
2017/01/04 16:47:22 [main.go:196] [I] PrivilegeMode is enabled, you should pay more attention to security issues
2017/01/04 16:47:22 [control.go:39] [D] Get new connection, x.x.x.x:34880 //真实ip替换了,下同。
2017/01/04 16:47:22 [control.go:64] [D] Get msg from frpc: {"type":0,"proxy_name":"abc","auth_key":"xxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"udp","remote_port":0,"custom_domains":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483519582}

2017/01/04 16:47:22 [control.go:344] [I] ProxyName [abc], start proxy success
2017/01/04 16:47:42 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:48:02 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:48:22 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:48:42 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:49:02 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:49:22 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:49:42 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:50:02 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:50:15 [control.go:147] [W] ProxyName [abc], client is dead!
2017/01/04 16:50:15 [control.go:112] [I] ProxyName [abc], I'm dead!
2017/01/04 16:50:15 [control.go:121] [D] ProxyName [abc], goroutine for noticing user conn is closed
2017/01/04 16:50:15 [server.go:175] [I] ProxyName [abc], udp listener is closed
2017/01/04 16:53:31 [control.go:39] [D] Get new connection, x.x.x.x:35011
2017/01/04 16:53:31 [control.go:64] [D] Get msg from frpc: {"type":0,"proxy_name":"abc","auth_key":"xxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"udp","remote_port":0,"custom_domains":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483519951}

2017/01/04 16:53:31 [control.go:344] [I] ProxyName [abc], start proxy success
2017/01/04 16:53:31 [control.go:39] [D] Get new connection, x.x.x.x:35014
2017/01/04 16:53:31 [control.go:64] [D] Get msg from frpc: {"type":6,"proxy_name":"abc","auth_key":"xxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"","remote_port":0,"custom_domains":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483519951}

2017/01/04 16:53:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:54:11 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 16:54:31 [control.go:167] [D] ProxyName [abc], get heartbeat

...

//大约在20:13时,尝试从外网访问frp服务,一直无法成功。下面是这段时间的frps log

2017/01/04 20:12:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:13:11 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:13:31 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:13:51 [server.go:301] [W] ProxyName [abc], work connection for udp closed
2017/01/04 20:13:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:14:11 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:14:18 [server.go:328] [D] ProxyName [abc], write to work connection for udp error: write tcp y.y.y.y:6000->x.x.x.x:35014: write: broken pipe
2017/01/04 20:14:31 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:14:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 20:15:11 [control.go:167] [D] ProxyName [abc], get heartbeat


frpc.log

//下午16:52启动frpc

2017/01/04 16:52:31 [main.go:109] [I] Start frpc success
2017/01/04 16:52:31 [control.go:180] [D] ProxyName [abc], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 16:52:31 [control.go:193] [I] ProxyName [abc], connect to server [z.z.z.z:6000] success!
2017/01/04 16:52:31 [control.go:207] [I] Start to send heartbeat to frps
2017/01/04 16:52:31 [client.go:61] [I] ProxyName [abc], udp tunnel reconnect to server [z.z.z.z:6000] success
2017/01/04 16:52:51 [control.go:211] [D] Send heartbeat to server
2017/01/04 16:52:51 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 16:53:11 [control.go:211] [D] Send heartbeat to server
2017/01/04 16:53:11 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 16:53:31 [control.go:211] [D] Send heartbeat to server
2017/01/04 16:53:31 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 16:53:51 [control.go:211] [D] Send heartbeat to server

...

2017/01/04 20:13:31 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:13:31 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:13:51 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:13:51 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:14:11 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:14:11 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:14:31 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:14:31 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:14:51 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:14:51 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:15:11 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:15:11 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 20:15:31 [control.go:211] [D] Send heartbeat to server
2017/01/04 20:15:31 [control.go:101] [D] ProxyName [abc], receive heartbeat response

...


frp服务可用的log

说明:21:11重启frpc,连接上frps,尝试使用frp服务,成功。frpc和frps的时间有一点不同步,frpc比frps时间大约慢1分钟。


frps.log

2017/01/04 21:10:11 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:10:31 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:10:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:11:11 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:11:31 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:11:51 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:12:09 [control.go:147] [W] ProxyName [abc], client is dead!
2017/01/04 21:12:09 [control.go:112] [I] ProxyName [abc], I'm dead!
2017/01/04 21:12:09 [control.go:121] [D] ProxyName [abc], goroutine for noticing user conn is closed
2017/01/04 21:12:09 [server.go:175] [I] ProxyName [abc], udp listener is closed
2017/01/04 21:12:27 [control.go:39] [D] Get new connection, x.x.x.x:34919
2017/01/04 21:12:27 [control.go:64] [D] Get msg from frpc: {"type":0,"proxy_name":"abc","auth_key":"xxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"udp","remote_port":0,"custom_domains":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483535486}

2017/01/04 21:12:27 [control.go:344] [I] ProxyName [abc], start proxy success
2017/01/04 21:12:47 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:12:47 [control.go:39] [D] Get new connection, x.x.x.x:34946
2017/01/04 21:12:47 [control.go:64] [D] Get msg from frpc: {"type":6,"proxy_name":"abc","auth_key":"xxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"","remote_port":0,"custom_domains":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483535507}

2017/01/04 21:13:07 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:13:27 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:13:47 [control.go:167] [D] ProxyName [abc], get heartbeat
2017/01/04 21:14:07 [control.go:167] [D] ProxyName [abc], get heartbeat


frpc.log

//21:11重启frpc,连接上frps,尝试使用frp服务,成功。

2017/01/04 21:11:21 [main.go:109] [I] Start frpc success
2017/01/04 21:11:26 [control.go:180] [D] ProxyName [abc], read [{"type":3,"code":0,"msg":""}
]
2017/01/04 21:11:26 [control.go:193] [I] ProxyName [abc], connect to server [z.z.z.z:6000] success!
2017/01/04 21:11:26 [control.go:207] [I] Start to send heartbeat to frps
2017/01/04 21:11:46 [control.go:211] [D] Send heartbeat to server
2017/01/04 21:11:46 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 21:11:47 [client.go:61] [I] ProxyName [abc], udp tunnel reconnect to server [z.z.z.z:6000] success
2017/01/04 21:12:06 [control.go:211] [D] Send heartbeat to server
2017/01/04 21:12:06 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 21:12:26 [control.go:211] [D] Send heartbeat to server
2017/01/04 21:12:26 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 21:12:46 [control.go:211] [D] Send heartbeat to server
2017/01/04 21:12:46 [control.go:101] [D] ProxyName [abc], receive heartbeat response
2017/01/04 21:13:06 [control.go:211] [D] Send heartbeat to server
2017/01/04 21:13:06 [control.go:101] [D] ProxyName [abc], receive heartbeat response

@fatedier
Copy link
Owner

fatedier commented Jan 4, 2017

应该是 udp 类型的 proxy 重连有问题(tcp 应该是正常的),我需要验证下,感谢反馈。

@fatedier
Copy link
Owner

fatedier commented Jan 4, 2017

udp 类型的重连机制确实存在 bug,待修复。

@fatedier fatedier changed the title heartbeat问题:空闲时无法维持client与server之间的heartbeat,连接丢失 heartbeat问题:udp proxy 空闲时无法维持client与server之间的heartbeat,连接丢失 Jan 4, 2017
@goer99
Copy link
Author

goer99 commented Jan 5, 2017

感谢做出了这么好用的软件,期待越做越好。:)

@fatedier
Copy link
Owner

fatedier commented Jan 5, 2017

这个问题已经 fix 了,会在 0.9.2 版本里更新。我简单测了下没什么问题,方便的话可以加群 606194980,我给你编译好的版本帮忙验证下。

@goer99
Copy link
Author

goer99 commented Jan 7, 2017

新版本仍然有问题,连接不上。

log见下面,也没看出什么来。

frps.log

2017/01/07 20:35:08 [main.go:194] [I] Start frps success
2017/01/07 20:35:08 [main.go:196] [I] PrivilegeMode is enabled, you should pay more attention to security issues
2017/01/07 20:35:29 [control.go:39] [D] Get new connection, x.x.x.x:34842
2017/01/07 20:35:29 [control.go:64] [D] Get msg from frpc: {"type":0,"proxy_name":"abc","auth_key":"xxxxxxxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"udp","remote_port":0,"custom_domains":null,"locations":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483792529}

2017/01/07 20:35:29 [control.go:338] [I] ProxyName [abc], start proxy success
2017/01/07 20:35:39 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:35:49 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:35:59 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:09 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:19 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:22 [control.go:39] [D] Get new connection, x.x.x.x:34919
2017/01/07 20:36:22 [control.go:64] [D] Get msg from frpc: {"type":6,"proxy_name":"abc","auth_key":"xxxxxxxxxxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"","remote_port":0,"custom_domains":null,"locations":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483792582}

2017/01/07 20:36:29 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:39 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:49 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:36:59 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:37:09 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:37:19 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:37:29 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:37:39 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:37:40 [control.go:143] [W] ProxyName [abc], client is dead!
2017/01/07 20:37:40 [control.go:108] [I] ProxyName [abc], I'm dead!
2017/01/07 20:37:40 [control.go:117] [D] ProxyName [abc], goroutine for noticing user conn is closed
2017/01/07 20:37:40 [server.go:368] [W] ProxyName [abc], work connection for udp closed
2017/01/07 20:37:40 [server.go:221] [I] ProxyName [abc], udp listener is closed
2017/01/07 20:38:37 [control.go:39] [D] Get new connection, x.x.x.x:35071
2017/01/07 20:38:37 [control.go:64] [D] Get msg from frpc: {"type":0,"proxy_name":"abc","auth_key":"xxxxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"udp","remote_port":0,"custom_domains":null,"locations":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483792717}

2017/01/07 20:38:37 [control.go:338] [I] ProxyName [abc], start proxy success
2017/01/07 20:38:42 [control.go:39] [D] Get new connection, x.x.x.x:34823
2017/01/07 20:38:42 [control.go:64] [D] Get msg from frpc: {"type":6,"proxy_name":"abc","auth_key":"xxxxxxxxxxxxxxx","use_encryption":false,"use_gzip":false,"pool_count":0,"privilege_mode":false,"privilege_key":"","proxy_type":"","remote_port":0,"custom_domains":null,"locations":null,"host_header_rewrite":"","http_username":"","http_password":"","subdomain":"","timestamp":1483792722}

2017/01/07 20:38:47 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:38:57 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 20:39:07 [control.go:163] [D] ProxyName [abc], get heartbeat

...

2017/01/07 21:18:27 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 21:18:37 [control.go:163] [D] ProxyName [abc], get heartbeat
2017/01/07 21:18:47 [control.go:163] [D] ProxyName [abc], get heartbeat


frpc.log

2017/01/07 20:38:36 [main.go:109] [I] Start frpc success
2017/01/07 20:38:37 [control.go:193] [D] ProxyName [abc], read [{"type":3,"code":0,"msg":""}
]
2017/01/07 20:38:37 [control.go:206] [I] ProxyName [abc], connect to server [x.x.x.x:6000] success!
2017/01/07 20:38:37 [control.go:220] [I] Start to send heartbeat to frps
2017/01/07 20:38:42 [client.go:65] [I] ProxyName [abc], udp tunnel connect to server [x.x.x.x:6000] success
2017/01/07 20:38:47 [control.go:224] [D] Send heartbeat to server
2017/01/07 20:38:47 [control.go:113] [D] ProxyName [abc], receive heartbeat response
2017/01/07 20:38:57 [control.go:224] [D] Send heartbeat to server
2017/01/07 20:38:57 [control.go:113] [D] ProxyName [abc], receive heartbeat response

...

2017/01/07 21:17:57 [control.go:224] [D] Send heartbeat to server
2017/01/07 21:17:57 [control.go:113] [D] ProxyName [abc], receive heartbeat response
2017/01/07 21:18:07 [control.go:224] [D] Send heartbeat to server
2017/01/07 21:18:07 [control.go:113] [D] ProxyName [abc], receive heartbeat response

@fatedier
Copy link
Owner

fatedier commented Jan 7, 2017

日志里看已经重连成功了,检查下是否是其他的问题。

@goer99
Copy link
Author

goer99 commented Jan 8, 2017

验证了三次,都无法连接。log记录的内容比较有限,所以无法看出是什么问题。

补充一些情况说明和建议:

1、当无法使用frp服务时,只有重启frpc,udp proxy才能重新使用,重启frps是不行的。

2、log中没有记录与udp proxy使用方(第三方)的交互情况,因此,看不到是否frps与udp proxy使用方之间的交互(端口监听、转发),以及frps是否向frpc转发了第三方的请求,进而也看不到是否frpc是否收到了frps转发过来的第三方请求及后续行为。

3、建议debug log中增加对frpc、frps、第三方之间转发消息的记录,或者在配置文件中增加这种debug记录开关。便于进一步定位问题。

@fatedier
Copy link
Owner

fatedier commented Jan 8, 2017

描述一下你出现这个问题的过程?

我本地测试了重启 frps,以及直接断网后恢复这两种情况,都是可以重连上的。

@goer99
Copy link
Author

goer99 commented Jan 8, 2017

过程描述:

  1. 启动frps;
  2. 启动frpc;查看frps 和frpc的log,确认已经连上;
  3. 第三方使用udp proxy,工作正常;
  4. 以上3步骤都是接连进行的,间隔时间不超过5分钟;
  5. 第三方停止使用udp proxy;
  6. 过20分钟。
  7. 第三方使用udp proxy,无响应;
  8. 重启frpc;
  9. 第三方使用udp proxy,工作正常。

注:udp proxy转发的是openvpn业务,你可以尝试一下是否与此有关。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants