Unexpected disconnect issue with Openfire 3.9.3/3.10.0/3.10.1

Dear All,

Greetings from India !!

We have setup Openfire 3.9.3(previously 3.5.2) in our company since almost 1.5 years and people are happily using it. In addition, we have customized Spark for Windows OS and an android client(Conversations) to communicate easily. We are serving ~1200 concurrent clients who are using this application.

All of sudden, since last four days we are facing some issues on server due to which clients get disconnected at frequent interval even though we didn’t do any configuration change on server. Looking at error.log file we found that an error is generated on each packet exchange between client and server.

We tried to migrate to different server (3.10.0, 3.10.1, 3.9.3). Please find error mentioned below. Please help us as this is 5th day and we are yet to find root cause of it.

debug.log

java.lang.NullPointerException

at org.jivesoftware.util.WebManager.getUser(WebManager.java:147)

at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:154)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.ja va:1652)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:22 3)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:11 27)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185 )

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:106 1)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandler Collection.java:215)

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.jav a:110)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)

at org.eclipse.jetty.server.Server.handle(Server.java:497)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)

at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635 )

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)

at java.lang.Thread.run(Unknown Source)

error.log

2015.06.21 10:44:21 org.jivesoftware.openfire.nio.NIOConnection - Failed to deliver packet:

2015.06.21 10:44:21 org.jivesoftware.openfire.session.LocalSession - Internal server error

java.lang.IllegalStateException: Connection closed

at org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:316)

at org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession .java:857)

at org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:289)

at org.jivesoftware.openfire.spi.RoutingTableImpl.routeToLocalDomain(RoutingTableI mpl.java:354)

at org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.jav a:239)

at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:170)

at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:84)

at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:84)

at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:65)

at org.jivesoftware.openfire.muc.spi.LocalMUCRole.send(LocalMUCRole.java:266)

at org.jivesoftware.openfire.muc.spi.LocalMUCRoom.broadcast(LocalMUCRoom.java:1153 )

at org.jivesoftware.openfire.muc.cluster.BroadcastPresenceRequest$1.run(BroadcastP resenceRequest.java:71)

at org.jivesoftware.openfire.muc.cluster.MUCRoomTask.execute(MUCRoomTask.java:85)

at org.jivesoftware.openfire.muc.cluster.BroadcastPresenceRequest.run(BroadcastPre senceRequest.java:69)

at org.jivesoftware.openfire.muc.spi.LocalMUCRoom.broadcastPresence(LocalMUCRoom.j ava:1106)

at org.jivesoftware.openfire.muc.spi.LocalMUCRoom.leaveRoom(LocalMUCRoom.java:826)

at org.jivesoftware.openfire.muc.spi.LocalMUCUser.process(LocalMUCUser.java:552)

at org.jivesoftware.openfire.muc.spi.LocalMUCUser.process(LocalMUCUser.java:197)

at org.jivesoftware.openfire.muc.spi.MultiUserChatServiceImpl.processPacket(MultiU serChatServiceImpl.java:331)

at org.jivesoftware.openfire.component.InternalComponentManager$RoutableComponents .process(InternalComponentManager.java:591)

at org.jivesoftware.openfire.spi.RoutingTableImpl.routeToComponent(RoutingTableImp l.java:401)

at org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.jav a:243)

at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:170)

at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:84)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.broadcastUnavailableFor DirectedPresences(PresenceUpdateHandler.java:489)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:163)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:137)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:201)

at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:148)

at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:84)

at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:84)

at org.jivesoftware.openfire.SessionManager$ClientSessionListener.onConnectionClos e(SessionManager.java:1242)

at org.jivesoftware.openfire.nio.NIOConnection.notifyCloseListeners(NIOConnection. java:292)

at org.jivesoftware.openfire.nio.NIOConnection.close(NIOConnection.java:275)

at org.jivesoftware.openfire.nio.ConnectionHandler.inputClosed(ConnectionHandler.j ava:114)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.inputClosed(De faultIoFilterChain.java:834)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$5(DefaultIoFilterC hain.java:607)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.inputClosed(D efaultIoFilterChain.java:938)

at org.apache.mina.core.filterchain.IoFilterAdapter.inputClosed(IoFilterAdapter.ja va:137)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$5(DefaultIoFilterC hain.java:607)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.inputClosed(D efaultIoFilterChain.java:938)

at org.apache.mina.core.filterchain.IoFilterAdapter.inputClosed(IoFilterAdapter.ja va:137)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$5(DefaultIoFilterC hain.java:607)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.inputClosed(D efaultIoFilterChain.java:938)

at org.apache.mina.core.filterchain.IoFilterAdapter.inputClosed(IoFilterAdapter.ja va:137)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$5(DefaultIoFilterC hain.java:607)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.inputClosed(D efaultIoFilterChain.java:938)

at org.apache.mina.core.filterchain.IoFilterAdapter.inputClosed(IoFilterAdapter.ja va:137)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$5(DefaultIoFilterC hain.java:607)

at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.inputClosed(D efaultIoFilterChain.java:938)

at org.apache.mina.core.filterchain.IoFilterAdapter.inputClosed(IoFilterAdapter.ja va:137)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextInputClosed(Defau ltIoFilterChain.java:611)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireInputClosed(DefaultIo FilterChain.java:604)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoP rocessor.java:729)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPolling IoProcessor.java:668)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPolling IoProcessor.java:657)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$10(AbstractPolli ngIoProcessor.java:654)

at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractP ollingIoProcessor.java:1121)

at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)

at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

at java.lang.Thread.run(Unknown Source)

warn.log

2015.06.21 16:10:49 org.jivesoftware.openfire.nio.ConnectionHandler - Closing connection due to exception in session: (0x00000016: nio socket, server, /103.36.45.118:26250 => 0.0.0.0/0.0.0.0:5222)

java.io.IOException: An existing connection was forcibly closed by the remote host

at sun.nio.ch.SocketDispatcher.read0(Native Method)

at sun.nio.ch.SocketDispatcher.read(Unknown Source)

at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)

at sun.nio.ch.IOUtil.read(Unknown Source)

at sun.nio.ch.SocketChannelImpl.read(Unknown Source)

at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:311)

at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:1)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoP rocessor.java:694)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPolling IoProcessor.java:668)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPolling IoProcessor.java:657)

at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$10(AbstractPolli ngIoProcessor.java:654)

at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractP ollingIoProcessor.java:1121)

at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)

at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

at java.lang.Thread.run(Unknown Source)

The specified item was not found. @wroot

Please try the test builds here or await a soon 3.10.2 release

Re: 100% CPU usage on 3.10.1

daryl

Daryl,

I can confirm that the above occurs with 3.10.2 as well under JRE7 build 80 and Centos 7.

I attach a log…
openfire_localsession_internal_error.txt.zip (7036 Bytes)