Openfire 3.10.0 Beta - High CPU usage

Hi all,

we had been running Openfire 3.9.3 and we were experiencing an issue that we need to restart openfire in a week or two, the problem was high cpu usage and high memory usage.

Recently we have updated our openfire installation to the beta (nightly openfire_2015-03-08.deb) and the things got worse yesterday we needed to restart every five minutes. I removed some plugins that were not used without change. With 3.9.3 the problem was high cpu and memory, seems now it is only the cpu.

Openfire 3.9.3 this is the memory and cpu graph

Screen Shot 2015-03-10 at 11.12.37 .pngScreen Shot 2015-03-10 at 11.14.46 .png

Openfire beta again memory and cpu:

Screen Shot 2015-03-10 at 11.13.14 .pngScreen Shot 2015-03-10 at 11.13.21 .png

Is there something we can do to catch that problem? Is there a common procedure we can do? Will the profile4j interrupt the service as it is production one and we have more then a thousand opened sessions, or it will interrupt only when we connect to the agent and it is ok to start openfire with profile4j enabled?

I tried to track down the threads with high cpu usage and here is what I had, although not sure how reliable this is (I used jstack and htop):

“NioProcessor-6” #73 prio=5 os_prio=0 tid=0x00007f83f4007800 nid=0x55a3 runnable [0x00007f83c22e1000]

java.lang.Thread.State: RUNNABLE

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

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(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

“NioProcessor-6” #73 prio=5 os_prio=0 tid=0x00007f83f4007800 nid=0x55a3 runnable [0x00007f83c22e1000]

java.lang.Thread.State: RUNNABLE

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

at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)

at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)

at sun.nio.ch.IOUtil.read(IOUtil.java:197)

at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)

  • locked <0x00000000c7491a88> (a java.lang.Object)

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(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

“NioProcessor-5” #69 prio=5 os_prio=0 tid=0x00007f83f4006000 nid=0x559f runnable [0x00007f83c26e5000]

java.lang.Thread.State: RUNNABLE

at sun.nio.ch.NativeThread.current(Native Method)

at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:326)

  • locked <0x00000000c71eca00> (a java.lang.Object)

  • locked <0x00000000c71ec9e0> (a java.lang.Object)

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(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

Thanks

damencho

Hello,

The current dev build has some issues with BOSH connections (at least) OF-890, could you try a build from March 6th to see if it CPU spikes as well?

daryl

We do not use BOSH, and it is disabled. We updated to openfire_2015-03-06.deb and we are monitoring.

No change. The same behavior. We even tried java7 and java8, both give the same result 200% of CPU after some time.

Please check openfire’s lib folder and make sure all of the jar files have roughly the same timestamp. There may be old/new content in there that should be blown out before upgrading/downgrading.

Confirm that all jars in lib folder has the same timestamp.

Here’s an older thread about the same issue (no solution though) 3.10 beta 100% cpu

We had to downgrade to 3.9.3 and will see now how it goes.

Hello Daryl,

I’am facing with the same issue. Java process hogging all my cpu (100%) on all threads within 2 days (around 150 users connected through a connection manager).

At this time I am running the Debian Build 1445 (http://bamboo.igniterealtime.org/browse/OPENFIRE-NIGHTLYDEB-1445) without any improvements.

**My OS platform is the following : **

~# lsb_release -a

No LSB modules are available.

Distributor ID: Ubuntu

Description: Ubuntu 14.04.2 LTS

Release: 14.04

Codename: trusty

My Java runtime environment :

JVM: Java HotSpot™ 64-Bit Server VM (25.31-b07, mixed mode)

Java: version 1.8.0_31, vendor Oracle Corporation

Java Home: /usr/lib/jvm/java-8-oracle/jre

VisualVM => Java culprit method Snapshot :

VisualVM Debug files Cpu Snapshot (CpuSnapshot.nps) and Thread Dump (threaddump-1426620520087.tdump)

Available here : http://we.tl/UoPqV368g9

Thanks for the detailed post. Yeah, Igniterealtime’s Openfire is currently chewing CPU in a similar fashion.

Seeing the same load currently with 3.9.3 and I see a lot of exceptions:

java.lang.IllegalStateException: Queue full

at java.util.AbstractQueue.add(AbstractQueue.java:98)

at org.jivesoftware.openfire.server.OutgoingSessionPromise.process(OutgoingSession Promise.java:184)

at org.jivesoftware.openfire.spi.RoutingTableImpl.routeToRemoteDomain(RoutingTable Impl.java:465)

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

just to give a feedback, I’m facing this issue too.

My environment is different, but the bahavior is the same.

I’m running Openfire 3.10.0 beta over a Windows Server 2012 R2.

It happens many times a day and I must kill the process via Task Manager and start the service again.

Hi Daniel.

It can be the caches with 100% of utilization, generaly is VCard and Rooster, The Warn logs can give you a clue of that, I set up both of them to “no limits”.

I ran for years Openfire (3.8.2, and 3.9.3) in Windows 2008 x64 and MySQL, and every week I faced problems with java memoy completely filled and CPU always 100%. Tired of it, I moved it to CentOS 6.5 x64, set up 2048MB to Java (in Windows I can’t set it more than 1536 because java was 32 bit) and the problems STOPED.

Now, CPU is no more than 5%, Ram is about 1GB of utilizatio and Java Memory is normally 20%.

1 Like

Hi Anderson.

Thanks for your help. I will change the cache settings and see the behavior.

unfortunately, it didn’t work.

I had to downgrade to 3.9.1. I’m using th 3.10.0 because it fixed the ghost sessions issue, created in the 3.9.3.

So, the 3.9.1 appears to be the right version to me at this time.

Thanks again Anderson.

Hi Daniel.
Few days ago Openfire goes to 3.10, and more people are facing problems with CPU usage…

“NioProcessor-26” prio=10 tid=0x00007fecf0008800 nid=0x7216 runnable [0x00007feda29e8000]

java.lang.Thread.State: RUNNABLE

at sun.nio.ch.NativeThread.current(Native Method)

at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:325)

  • locked <0x0000000782d821f8> (a java.lang.Object)

  • locked <0x0000000782d821d8> (a java.lang.Object)

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(ThreadPoolExecutor.java:1145)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

“Component-Thread-2” daemon prio=10 tid=0x00007fecc8003000 nid=0x7213 waiting on condition [0x00007feda2ae9000]

java.lang.Thread.State: TIMED_WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

  • parking to wait for <0x00000007806e06c0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNano s(AbstractQueuedSynchronizer.java:2082)

at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.fetchSession(O rderedThreadPoolExecutor.java:730)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:683)

at java.lang.Thread.run(Thread.java:745)

“NioProcessor-32” prio=10 tid=0x00007fecf0007000 nid=0x7212 runnable [0x00007feda2bea000]

java.lang.Thread.State: RUNNABLE

=====================================

I have too;

Has been rolled back to 3.8.2

I can provide some stack, if necessary.

I have opened a issue at mina:

[DIRMINA-1011] 100% load in Mina when using openfire 3.10.0 - ASF JIRA

1 Like

Hi same pb for us. Since we’ve Upgrdade to 3.9.10 version 100% CPU usage every day. CPU usage is increasing slowly until openfire crash.

We have tried new installation with new OS install but same pb.

Our configuration Ubuntu 14.04.2 LTS + openfire 3.9.10 + java version "1.7.0_79 OpenJDK Runtime Environment (IcedTea 2.5.5) (7u79-2.5.5-0ubuntu0.14.04.2)

OpenJDK 64-Bit Server VM (build 24.79-b02, mixed mode)

Hope the next release will fix.

Alban

Our log

@

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Order edThreadPoolExecutor.java:761)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:703)

at java.lang.Thread.run(Thread.java:745)

2015.05.21 15:18:36 org.jivesoftware.openfire.nio.NIOConnection - Failed to deliver packet: JITSI_ROSTER

2015.05.21 15:18:36 org.jivesoftware.openfire.session.LocalSession - Erreur interne du serveur

java.lang.IllegalStateException: Connection closed

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

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.SessionManager.userBroadcast(SessionManager.java:1068 )

at org.jivesoftware.openfire.roster.Roster.broadcast(Roster.java:685)

at org.jivesoftware.openfire.roster.Roster.broadcast(Roster.java:718)

at org.jivesoftware.openfire.roster.Roster.(Roster.java:163)

at org.jivesoftware.openfire.roster.RosterManager.getRoster(RosterManager.java:116 )

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.broadcastUpdate(Presenc eUpdateHandler.java:307)

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

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:240)

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

at org.jivesoftware.openfire.nio.ConnectionHandler.sessionIdle(ConnectionHandler.j ava:142)

at org.jivesoftware.openfire.nio.ClientConnectionHandler.sessionIdle(ClientConnect ionHandler.java:88)

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

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextSessionIdle(Defau ltIoFilterChain.java:521)

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

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

at org.apache.mina.core.filterchain.IoFilterAdapter.sessionIdle(IoFilterAdapter.ja va:95)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextSessionIdle(Defau ltIoFilterChain.java:521)

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

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

at org.apache.mina.core.filterchain.IoFilterAdapter.sessionIdle(IoFilterAdapter.ja va:95)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextSessionIdle(Defau ltIoFilterChain.java:521)

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

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

at org.apache.mina.core.filterchain.IoFilterAdapter.sessionIdle(IoFilterAdapter.ja va:95)

at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextSessionIdle(Defau ltIoFilterChain.java:521)

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

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

at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:97)

at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ordere dThreadPoolExecutor.java:769)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Order edThreadPoolExecutor.java:761)

at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:703)

at java.lang.Thread.run(Thread.java:745)