Projects tigase _server server-core Issues #1069
BindException: Address already in use (#1069)
wojciech.kapcia@tigase.net opened 5 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
Andrzej Wójcik (Tigase) commented 5 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 5 years ago

I'm reassigning back to me as the fix is not working in all cases.

Andrzej Wójcik (Tigase) commented 5 years ago

Now the issue is (I think so and hope so) fixed.

issue 1 of 1
Type
Bug
Priority
Normal
Assignee
Spent time
6h 45m
Issue Votes (0)
Watchers (0)
Reference
tigase/_server/server-core#1069
Please wait...
Page is in error, reload to recover