BindException: Address already in use (#1069)

Wojciech Kapcia (Tigase) opened 6 years ago

Recently it happens quite often on our installation, that Tigase fails to start listening on 5223 with following exception:

[2019-08-31 01:41:38:000] [FINE    ] [scheduler_pool-14-thread-1-c2s ] ConnectionManager.startService(): Starting service: {remote-host=localhost, port-no=5223, new-connections-throttling=50, ifc=[Ljava.lang.String;@7f80baec, socket=ssl, type=accept}
[2019-08-31 01:41:38:001] [WARNING ] [  ConnectionOpenThread ] ConnectionOpenThread.addAllWaiting(): Error: creating connection for: {remote-host=localhost, port-no=5223, new-connections-throttling=50, ifc=[Ljava.lang.String;@7f80baec, socket=ssl, type=accept}
java.net.BindException: Address already in use
        at java.base/sun.nio.ch.Net.$$YJP$$bind0(Native Method)
        at java.base/sun.nio.ch.Net.bind0(Net.java)
        at java.base/sun.nio.ch.Net.bind(Net.java:461)
        at java.base/sun.nio.ch.Net.bind(Net.java:453)
        at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227)
        at java.base/sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:80)
        at tigase.net.ConnectionOpenThread.addISA(ConnectionOpenThread.java:274)
        at tigase.net.ConnectionOpenThread.addPort(ConnectionOpenThread.java:307)
        at tigase.net.ConnectionOpenThread.addAllWaiting(ConnectionOpenThread.java:238)
        at tigase.net.ConnectionOpenThread.run(ConnectionOpenThread.java:207)
        at java.base/java.lang.Thread.run(Thread.java:834)

What's problematic/weird in this case, is that seems like a second call to start the service - there is already one before roughly 1 minute earlier:

[2019-08-31 01:40:42:496] [FINE    ] [       pool-1-thread-8 ] ConnectionManager.startService() : Starting service: {remote-host=localhost, port-no=5223, new-connections-throttling=50, ifc=[Ljava.lang.String;@7f80baec, socket=ssl, type=accept}

Same double entry happens for 5222, but it starts OK.

[2019-08-31 01:40:42:496] [FINE    ] [       pool-1-thread-8 ] ConnectionManager.startService() : Starting service: {remote-host=localhost, port-no=5222, new-connections-throttling=200, ifc=[Ljava.lang.String;@7f80baec, socket=plain, type=accept}
…
[2019-08-31 01:41:38:000] [FINE    ] [scheduler_pool-14-thread-1-c2s ] ConnectionManager.startService(): Starting service: {remote-host=localhost, port-no=5222, new-connections-throttling=200, ifc=[Ljava.lang.String;@7f80baec, socket=plain, type=accept}

I'm completely sure there is nothing listening on that port before starting Tigase:

kotali@ip-10-0-36-197:~$ sudo lsof -iTCP:5223 -sTCP:LISTEN -Pn | wc -l
0

Activities

Andrzej Wójcik (Tigase) commented 6 years ago

I've found an issue (possible race condition) in code responsible for port binding (connection manager initialization). I've fixed this issue and this should fix startup issue.
Andrzej Wójcik (Tigase) commented 6 years ago

I'm reassigning back to me as the fix is not working in all cases.
Andrzej Wójcik (Tigase) commented 6 years ago

Now the issue is (I think so and hope so) fixed.
Wojciech Kapcia (Tigase) added "Related" helpdesk/helpdesk-priv#1229 4 months ago
Login to comment

Type	Bug
Priority	Normal
Assignee	Wojciech Kapcia (Tigase)
Spent time	0

Issue Votes (0)

Watchers (2)

Reference

tigase/_server/server-core#1069