Possible concurrency issue (#1422)

Unknown opened 4 years ago

Describe the bug Sometimes at the startup I see in the logs:

[WARNING ] [  ConnectionOpenThread ] ConnectionOpenThread.processWaiting(): Error: creating connection for: {remote-host=localhost, port-no=5280, new-connections-throttling=1000, ifc=[Ljava.lang.String;@731d223f, socket=plain, type=accept}
java.net.BindException: Address already in use
	at java.base/sun.nio.ch.Net.bind0(Native Method)
	at java.base/sun.nio.ch.Net.bind(Net.java:455)
	at java.base/sun.nio.ch.Net.bind(Net.java:447)
	at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227)
	at tigase.net.ConnectionOpenThread.addISA(ConnectionOpenThread.java:297)
	at tigase.net.ConnectionOpenThread.addPort(ConnectionOpenThread.java:330)
	at tigase.net.ConnectionOpenThread.processWaiting(ConnectionOpenThread.java:229)
	at tigase.net.ConnectionOpenThread.run(ConnectionOpenThread.java:194)
	at java.base/java.lang.Thread.run(Thread.java:834)

To Reproduce It doesn't happens always, there is only one instance of tigase in the virtual machine and that port is not bound by any other process

Impact I don't know if the server works anyway correctly in this situation

Expected behavior No warning at startup

Details (please complete the following information):

Tigase version: 8.1.0-b10857
JVM flavour and version: openjdk 11.0.8 2020-07-14
Ubuntu 18.04.5 LTS

Unknown commented 4 years ago

How did you start the server (were you restarting)?

I don't know if the server works anyway correctly in this situation

The server itself should work just fine, but it wouldn't be accessible on the problematic port. You can execute lsof -iTCP -sTCP:LISTEN -Pn to see which ports are being listened on.

Unknown commented 4 years ago

I just shut down the server and restarted after some minutes, usually it works, when it happened I have executed:

# netstat -ltpn | grep 5280

but no results was given, that why I have assumed some kind of race condition in tigase setup binding

Unknown commented 4 years ago

Could you share your complete (obfuscated) config.tdsl? Do you have any connection-manager/port configuration there?

Unknown commented 4 years ago

excerpts from the config:

bosh {
    seeOtherHost (class: none) {}
}
c2s {
    connections {
        5222 {
            'new-connections-throttling' = 2000L
        }
    }
    seeOtherHost (class: none) {}
    'urn:xmpp:sm:3' () {
        active = true
    }
}
ws2s {
    connections {
        ports = [ 5290, 5291 ]
        5291 {
            socket = 'ssl'
            type = 'accept'
        }
    }
    seeOtherHost (class: none) {}
    'urn:xmpp:sm:3' {
        active = true
    }
}

@hantu85 do you think that reconfiguring CM beans to apply the configuration could cause such behaviour?

Unknown commented 4 years ago

Yes, it could as port 5291 is listed "twice", once in the ports property and also in as a separate entry.

I would suggest to change this part of the config to look like the following one:

bosh {
    seeOtherHost (class: none) {}
}
c2s {
    connections {
        5222 {
            'new-connections-throttling' = 2000L
        }
    }
    seeOtherHost (class: none) {}
    'urn:xmpp:sm:3' () {
        active = true
    }
}
ws2s {
    connections {
        5291 () {
            socket = 'ssl'
            type = 'accept'
        }
    }
    seeOtherHost (class: none) {}
    'urn:xmpp:sm:3' {
        active = true
    }
}

We can skip ports section as port 5290 is enabled by default and we want just to enable and configure port 5291.

Unknown commented 4 years ago

One thing - original exception was related to port 5280 (i.e. bosh), which doesn't list ports and only have specific see-other-host configuration.

Unknown commented 4 years ago

Then it should not cause such behaviour.

	Unknown opened 4 years ago Describe the bug Sometimes at the startup I see in the logs: [WARNING ] [ ConnectionOpenThread ] ConnectionOpenThread.processWaiting(): Error: creating connection for: {remote-host=localhost, port-no=5280, new-connections-throttling=1000, ifc=[Ljava.lang.String;@731d223f, socket=plain, type=accept} java.net.BindException: Address already in use at java.base/sun.nio.ch.Net.bind0(Native Method) at java.base/sun.nio.ch.Net.bind(Net.java:455) at java.base/sun.nio.ch.Net.bind(Net.java:447) at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227) at tigase.net.ConnectionOpenThread.addISA(ConnectionOpenThread.java:297) at tigase.net.ConnectionOpenThread.addPort(ConnectionOpenThread.java:330) at tigase.net.ConnectionOpenThread.processWaiting(ConnectionOpenThread.java:229) at tigase.net.ConnectionOpenThread.run(ConnectionOpenThread.java:194) at java.base/java.lang.Thread.run(Thread.java:834) To Reproduce It doesn't happens always, there is only one instance of tigase in the virtual machine and that port is not bound by any other process Impact I don't know if the server works anyway correctly in this situation Expected behavior No warning at startup Details (please complete the following information): Tigase version: 8.1.0-b10857 JVM flavour and version: openjdk 11.0.8 2020-07-14 Ubuntu 18.04.5 LTS
	Unknown commented 4 years ago How did you start the server (were you restarting)? I don't know if the server works anyway correctly in this situation The server itself should work just fine, but it wouldn't be accessible on the problematic port. You can execute `lsof -iTCP -sTCP:LISTEN -Pn` to see which ports are being listened on.
	Unknown commented 4 years ago I just shut down the server and restarted after some minutes, usually it works, when it happened I have executed: `# netstat -ltpn \| grep 5280` but no results was given, that why I have assumed some kind of race condition in tigase setup binding
	Unknown commented 4 years ago Could you share your complete (obfuscated) `config.tdsl`? Do you have any connection-manager/port configuration there?
	Unknown commented 4 years ago excerpts from the config: `bosh { seeOtherHost (class: none) {} } c2s { connections { 5222 { 'new-connections-throttling' = 2000L } } seeOtherHost (class: none) {} 'urn:xmpp:sm:3' () { active = true } } ws2s { connections { ports = [ 5290, 5291 ] 5291 { socket = 'ssl' type = 'accept' } } seeOtherHost (class: none) {} 'urn:xmpp:sm:3' { active = true } }` @hantu85 do you think that reconfiguring CM beans to apply the configuration could cause such behaviour?
	Unknown commented 4 years ago Yes, it could as port `5291` is listed "twice", once in the `ports` property and also in as a separate entry. I would suggest to change this part of the config to look like the following one: `bosh { seeOtherHost (class: none) {} } c2s { connections { 5222 { 'new-connections-throttling' = 2000L } } seeOtherHost (class: none) {} 'urn:xmpp:sm:3' () { active = true } } ws2s { connections { 5291 () { socket = 'ssl' type = 'accept' } } seeOtherHost (class: none) {} 'urn:xmpp:sm:3' { active = true } }` We can skip `ports` section as port `5290` is enabled by default and we want just to enable and configure port `5291`.
	Unknown commented 4 years ago One thing - original exception was related to port `5280` (i.e. bosh), which doesn't list ports and only have specific see-other-host configuration.
	Unknown commented 4 years ago Then it should not cause such behaviour.