NIOConnectionHandler logs null => 0.0.0.0

We’ve been seeing tons of these log messages on Openfire 4.5.2 and 4.6.1 w/hazelcast cluster plugin and clustering enabled. They might be benign, but they’re at WARN level. We’re unsure if they deserve action.

WARN  [socket_c2s-thread-3]: org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to exception in session: (0x00007CBF: nio socket, server, null => 0.0.0.0/0.0.0.0:5222)
java.io.IOException: Connection reset by peer
  1. I’ve looked at where this is logged in the source. Does anybody have an idea of what causes these?
  2. Why is server info “null => 0.0.0.0/0.0.0.0:5222” ?
  3. Are these log messages expected for normal/healthy server behavior?
  4. Can the log message (or logging from caller) be modified for more information?

Sometimes (not always) the above log message is followed by with a log message like this:

WARN  [socket_c2s-thread-4]: org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to exception in session: (0x0000AEF0: nio socket, server, null => 0.0.0.0/0.0.0.0:5222)
org.apache.mina.core.write.WriteToClosedSessionException: null
	at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.clearWriteRequestQueue(AbstractPollingIoProcessor.java:1190) ~[mina-core-2.1.3.jar:?]
	at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.removeNow(AbstractPollingIoProcessor.java:1151) ~[mina-core-2.1.3.jar:?]
	at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.removeSessions(AbstractPollingIoProcessor.java:864) ~[mina-core-2.1.3.jar:?]
	at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:694) ~[mina-core-2.1.3.jar:?]
	at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64) ~[mina-core-2.1.3.jar:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]

Anybody have feedback on this one?

Hi Free. On first glance, this looks relatively benign. It appears to be caused by a client connection that is being closed ‘uncleanly’ (eg: closing the TCP socket, without having sent a closing </stream:stream> element, or similar). The follow-up log message most likely is Openfire naively trying to tell that client (that’s now gone) that it has been disconnected.

There is a chance that the cause might not be with the client itself, but in some kind of network device in between Openfire and the client. If that’s the case, then it would be reasonable to assume that a lot of connections would drop in a similar manner at the same time.