[GH-ISSUE #3493] FRP Client reconnect fails because the same process is holding lock on proxy name/port #2792

Closed
opened 2026-05-05 13:48:06 -06:00 by gitea-mirror · 7 comments
Owner

Originally created by @pierre-pretorius on GitHub (Jun 22, 2023).
Original GitHub issue: https://github.com/fatedier/frp/issues/3493

Bug Description

Please look at the logs below. There are comments in between which explains the problem. A workaround to avoid the problem is to set a schedule to restart the FRPC process every day.

frpc Version

0.44.0

frps Version

0.45.0

System Architecture

linux/arm (client) and linux/amd64 (server)

Configurations

Server
[common]
bind_port = *******
authentication_method = token
token = ***************
dashboard_port = ****
dashboard_user = *********
dashboard_pwd = *********
log_file = /var/log/frps.log
log_level = warn

Client

[web]
type = tcp
local_port = 80
remote_port = 30000
use_encryption = true
use_compression = true

Logs

Client
The client runs successfully for many weeks, but then at some point starts saying "port unavailable" when it tries to reconnect.

Jun 22 16:22:01 pierre frpc[1585]: 2023/06/22 16:22:01 [W] [control.go:179] [4838aff45eb15596] [web] start error: port unavailable
Jun 22 16:22:34 pierre frpc[1585]: 2023/06/22 16:22:34 [W] [control.go:179] [4838aff45eb15596] [web] start error: port unavailable

I then force the port open on the server without doing anything on the client. The client error message then changes to "proxy name already in use":

Jun 22 16:23:07 pierre frpc[1585]: 2023/06/22 16:23:07 [W] [control.go:179] [4838aff45eb15596] [web] start error: proxy name [web] is already in use
Jun 22 16:23:40 pierre frpc[1585]: 2023/06/22 16:23:40 [W] [control.go:179] [4838aff45eb15596] [web] start error: proxy name [web] is already in use

I then restart the FRP client and it connects successfully. This seems to indicate the frpc client process had an open connection even though it was trying to reconnect.

Jun 22 16:28:01 pierre[1759468]: 2023/06/22 16:28:01 [I] [control.go:181] [e9f10a272b9c5514] [web] start proxy success

Server

After running successfully a long time, the server eventually says port is unavailable when the client reconnects:

2023/06/22 16:38:00 [W] [control.go:460] [4ddcec515a601934] new proxy [web] type [tcp] error: port unavailable

Then once we force the port open on the server:

2023/06/22 16:38:01 [W] [control.go:460] [4198c118cecfd995] new proxy [web] type [tcp] error: proxy name [web] is already in use

Steps to reproduce

We can't easily reproduce it. We run many thousands of clients and there are always at least 10+ stuck in this "Reconnect while proxy or port in use" mode which doesn't resolve by itself.

Affected area

  • Docs
  • Installation
  • Performance and Scalability
  • Security
  • User Experience
  • Test and Release
  • Developer Infrastructure
  • Client Plugin
  • Server Plugin
  • Extensions
  • Others
Originally created by @pierre-pretorius on GitHub (Jun 22, 2023). Original GitHub issue: https://github.com/fatedier/frp/issues/3493 ### Bug Description Please look at the logs below. There are comments in between which explains the problem. A workaround to avoid the problem is to set a schedule to restart the FRPC process every day. ### frpc Version 0.44.0 ### frps Version 0.45.0 ### System Architecture linux/arm (client) and linux/amd64 (server) ### Configurations **Server** [common] bind_port = ******* authentication_method = token token = *************** dashboard_port = **** dashboard_user = ********* dashboard_pwd = ********* log_file = /var/log/frps.log log_level = warn **Client** [web] type = tcp local_port = 80 remote_port = 30000 use_encryption = true use_compression = true ### Logs **Client** The client runs successfully for many weeks, but then at some point starts saying "port unavailable" when it tries to reconnect. ``` Jun 22 16:22:01 pierre frpc[1585]: 2023/06/22 16:22:01 [W] [control.go:179] [4838aff45eb15596] [web] start error: port unavailable Jun 22 16:22:34 pierre frpc[1585]: 2023/06/22 16:22:34 [W] [control.go:179] [4838aff45eb15596] [web] start error: port unavailable ``` I then force the port open on the server without doing anything on the client. The client error message then changes to "proxy name already in use": ``` Jun 22 16:23:07 pierre frpc[1585]: 2023/06/22 16:23:07 [W] [control.go:179] [4838aff45eb15596] [web] start error: proxy name [web] is already in use Jun 22 16:23:40 pierre frpc[1585]: 2023/06/22 16:23:40 [W] [control.go:179] [4838aff45eb15596] [web] start error: proxy name [web] is already in use ``` I then restart the FRP client and it connects successfully. This seems to indicate the frpc client process had an open connection even though it was trying to reconnect. ``` Jun 22 16:28:01 pierre[1759468]: 2023/06/22 16:28:01 [I] [control.go:181] [e9f10a272b9c5514] [web] start proxy success ``` **Server** After running successfully a long time, the server eventually says port is unavailable when the client reconnects: ``` 2023/06/22 16:38:00 [W] [control.go:460] [4ddcec515a601934] new proxy [web] type [tcp] error: port unavailable ``` Then once we force the port open on the server: ``` 2023/06/22 16:38:01 [W] [control.go:460] [4198c118cecfd995] new proxy [web] type [tcp] error: proxy name [web] is already in use ``` ### Steps to reproduce We can't easily reproduce it. We run many thousands of clients and there are always at least 10+ stuck in this "Reconnect while proxy or port in use" mode which doesn't resolve by itself. ### Affected area - [ ] Docs - [ ] Installation - [ ] Performance and Scalability - [ ] Security - [ ] User Experience - [ ] Test and Release - [ ] Developer Infrastructure - [X] Client Plugin - [x] Server Plugin - [ ] Extensions - [ ] Others
gitea-mirror 2026-05-05 13:48:06 -06:00
Author
Owner

@fatedier commented on GitHub (Jun 25, 2023):

force the port open on the server

What specific operation was performed?

Could you please provide more detailed logs when frpc is disconnected?

<!-- gh-comment-id:1605834768 --> @fatedier commented on GitHub (Jun 25, 2023): > force the port open on the server What specific operation was performed? Could you please provide more detailed logs when frpc is disconnected?
Author
Owner

@pierre-pretorius commented on GitHub (Jun 26, 2023):

What specific operation was performed?

We run this command on the FRPS server, using the IP address of the FRPC client:

sudo tcpkill -i ens5 host <client_ip>

Could you please provide more detailed logs when frpc is disconnected?

I will investigate again and post a longer log.

<!-- gh-comment-id:1607985673 --> @pierre-pretorius commented on GitHub (Jun 26, 2023): > What specific operation was performed? We run this command on the FRPS server, using the IP address of the FRPC client: ``` sudo tcpkill -i ens5 host <client_ip> ``` > Could you please provide more detailed logs when frpc is disconnected? I will investigate again and post a longer log.
Author
Owner

@fatedier commented on GitHub (Jun 27, 2023):

By the way, if you can upgrade to the latest version v0.50.0, it would be better.

<!-- gh-comment-id:1608654800 --> @fatedier commented on GitHub (Jun 27, 2023): By the way, if you can upgrade to the latest version v0.50.0, it would be better.
Author
Owner

@fatedier commented on GitHub (Jun 27, 2023):

In addition, it is important to know why the connection between frpc and frps is being disconnected. Is it due to a machine malfunction on frps, network fluctuations, or other reasons? To track these issues, more detailed logs are needed.

<!-- gh-comment-id:1608665584 --> @fatedier commented on GitHub (Jun 27, 2023): In addition, it is important to know why the connection between frpc and frps is being disconnected. Is it due to a machine malfunction on frps, network fluctuations, or other reasons? To track these issues, more detailed logs are needed.
Author
Owner

@pierre-pretorius commented on GitHub (Jul 14, 2023):

We upgrade to v0.50.0 with config below and found the root cause.

[web]
type = tcp
local_port = 80
remote_port = 30000
use_encryption = true
use_compression = true

After the server is running for a day or so, about 0.1% of the FRP clients are continuously trying to connect but fail:

Jul 11 13:55:31 pierre frpc[1585]: 2023/07/11 13:55:31 [W] [control.go:172] [c4221d7b74461a6] [web] start error: port unavailable

On the server we can see that an nginx processes is still connected to the port 30000 of FRPS even though the FRP client is disconnected and is trying to re-establish connection. On server:

$ sudo netstat -anp | grep 30001 | grep nginx

tcp        0      0 127.0.0.1:38580         127.0.0.1:30000         TIME_WAIT 1451964/nginx: work 

If we kill the nginx process, then the netstat connection above disappears and the FRP client stops looping and reconnects successfully. This means it's somehow possible for a connection to the remote_port on the server to stop the FRP client from connecting again after it drops. In our case the nginx proxy_pass directive is making the connection.

We found two possible workarounds (both work):
a) Configure your nginx to periodically shutdown and recycle workers. This has the unfortunate side effect of dropping existing web sockets. FRP clients will be in reconnect loop for a while until nginx worker is recycled.
b) Create a script that reads the FRPS log and detects a FRP client is continuously unable to connect, then it uses tcpkill to close any connection to the remote_port on the server. In our case this closes the nginx proxy_pass connection:

tcpkill -i lo port 30000

We currently use workaround (b) and abandoned workaround (a).

<!-- gh-comment-id:1635206395 --> @pierre-pretorius commented on GitHub (Jul 14, 2023): We upgrade to v0.50.0 with config below and found the root cause. ``` [web] type = tcp local_port = 80 remote_port = 30000 use_encryption = true use_compression = true ``` After the server is running for a day or so, about 0.1% of the FRP clients are continuously trying to connect but fail: ``` Jul 11 13:55:31 pierre frpc[1585]: 2023/07/11 13:55:31 [W] [control.go:172] [c4221d7b74461a6] [web] start error: port unavailable ``` On the server we can see that an nginx processes is still connected to the port 30000 of FRPS even though the FRP client is disconnected and is trying to re-establish connection. On server: ``` $ sudo netstat -anp | grep 30001 | grep nginx tcp 0 0 127.0.0.1:38580 127.0.0.1:30000 TIME_WAIT 1451964/nginx: work ``` If we kill the nginx process, then the netstat connection above disappears and the FRP client stops looping and reconnects successfully. This means it's somehow possible for a connection to the remote_port on the server to stop the FRP client from connecting again after it drops. In our case the nginx proxy_pass directive is making the connection. We found two possible workarounds (both work): a) Configure your nginx to periodically shutdown and recycle workers. This has the unfortunate side effect of dropping existing web sockets. FRP clients will be in reconnect loop for a while until nginx worker is recycled. b) Create a script that reads the FRPS log and detects a FRP client is continuously unable to connect, then it uses tcpkill to close any connection to the remote_port on the server. In our case this closes the nginx proxy_pass connection: ``` tcpkill -i lo port 30000 ``` We currently use workaround (b) and abandoned workaround (a).
Author
Owner

@fatedier commented on GitHub (Jul 14, 2023):

@pierre-pretorius Great.

However, I am still a bit confused. Normally, the TIME_WAIT connection that you find through netstat should not affect frps from re-listening on port 30000. Can you filter not only the connections of nginx but also all connections on port 30000?

<!-- gh-comment-id:1635221794 --> @fatedier commented on GitHub (Jul 14, 2023): @pierre-pretorius Great. However, I am still a bit confused. Normally, the TIME_WAIT connection that you find through netstat should not affect frps from re-listening on port 30000. Can you filter not only the connections of nginx but also all connections on port 30000?
Author
Owner

@github-actions[bot] commented on GitHub (Aug 21, 2023):

Issues go stale after 30d of inactivity. Stale issues rot after an additional 7d of inactivity and eventually close.

<!-- gh-comment-id:1685450503 --> @github-actions[bot] commented on GitHub (Aug 21, 2023): Issues go stale after 30d of inactivity. Stale issues rot after an additional 7d of inactivity and eventually close.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: github-starred/frp#2792
No description provided.