powered by Jive Software

Wildfire service use 99% CPU

Hi, I run Wildfire 2.4.4 on Win NT server, sometimes in the task manager I see the wildfire service run with 99% of CPU, I restart the service and this percentage fall to 00%.

What happens with wildfire it consumes as much CPU?

Same here, but with the server running on Debian Sarge with Sun’'s JDK 1.5 update 6. It consumes an entire HyperThreading CPU… Any solution how to fix this (2.4.4 that is)?

Hi,

are you using more than 90 % of the available memory (look at Wildfire’‘s /index.jsp)? Maybe you want to run Wildfire with “-verbose:gc” so you’'ll see if it busy because of too much garbage collections. Increasing the Xmx value will help a lot if this is the case.

LG

PS: http://www.jivesoftware.org/community/thread.jspa?threadID=17641 is also about 99% CPU.

Thanks for the pointer it2000. Well, no it does only use 25% of the available memory, and outside of Java there’‘s enough virtual one, so that shouldn’‘t be a problem. There isn’'t even load on the server, being newly deployed.

No, I use the standard configuration for the memory.

P.D.: The memory usage never surpasses 50 %, the graphics of statics plugin say that, the problem is de CPU usage.

Hi,

Wildfire shows you on the index.jsp page the “java max memory value” Xmx. If it is 64 MB (and your server has 6 GB) then the process inside the JVM will never use more than 64 MB.

But this does not seem to be the origin of the problem, anyway it would not be wrong to monitor the memory usage a little bit. http://www.tagtraum.com/gcviewer.html describes how to set this up to get very nice GC usage pictures and how to tune the JVM.

Are there any errors in your log files which could indicate why Wildfire uses so much memory.

Currently there is no trace mode available and the debug mode also logs only some things so it could be hard to find the looping threads.

One need to get a stack trace to get the looping threads, please see http://tmitevski.users.mcs2.netarray.com/tracehowtos.do for details (win32+unix). There’'s also a Webstart tool to create stack traces.

LG

Actually backtraces on Linux are as easy as killall -QUIT java:

Full thread dump Java HotSpot™ Server VM (1.5.0_06-b05 mixed mode):

“pool-2-thread-5” prio=1 tid=0x08324d90 nid=0x6bee waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“pool-2-thread-4” prio=1 tid=0x08383890 nid=0x6b19 waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“pool-2-thread-3” prio=1 tid=0x08383d50 nid=0x635b waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“pool-2-thread-2” prio=1 tid=0x085b1078 nid=0x5daf waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“pool-2-thread-1” prio=1 tid=0x081ae780 nid=0x5dae waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“Queued Packets Processor” daemon prio=1 tid=0x081aefb0 nid=0x5dad waiting on condition

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

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Abs tractQueuedSynchronizer.java:1767)

at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359)

at org.jivesoftware.wildfire.server.OutgoingSessionPromise$1.run(OutgoingSessionPr omise.java:86)

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

“SunJsseListener1-1” prio=1 tid=0xa80ffac0 nid=0x5bfd in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaae0e288> (a org.mortbay.util.ThreadPool$PoolThread)
    at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:522)
  • locked <0xaae0e288> (a org.mortbay.util.ThreadPool$PoolThread)

“SunJsseListener1-0” prio=1 tid=0xa827b250 nid=0x5bfc in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaae0e300> (a org.mortbay.util.ThreadPool$PoolThread)
    at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:522)
  • locked <0xaae0e300> (a org.mortbay.util.ThreadPool$PoolThread)

“Acceptor [SSL: ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=9091]]” prio=1 tid=0xa8260e10 nid=0x5bfb runnable

at java.lang.String.intern(Native Method)

at java.lang.Class.searchMethods(Class.java:2587)

at java.lang.Class.getMethod0(Class.java:2611)

at java.lang.Class.getMethod0(Class.java:2620)

at java.lang.Class.getMethod0(Class.java:2620)

at java.lang.Class.getMethod(Class.java:1579)

at org.mortbay.log.OutputStreamLogSink.expandThrowable(OutputStreamLogSink.java:58 2)

at org.mortbay.log.OutputStreamLogSink.formatObject(OutputStreamLogSink.java:538)

  • locked <0xaad12b40> (a java.io.PrintWriter)
    at org.mortbay.log.OutputStreamLogSink.formatObject(OutputStreamLogSink.java:521)
    at org.mortbay.log.OutputStreamLogSink.log(OutputStreamLogSink.java:382)
  • locked <0xaad12ab0> (a org.mortbay.log.OutputStreamLogSink)
    at org.mortbay.log.LogImpl.message(LogImpl.java:428)
  • locked <0xaad13978> (a org.mortbay.log.LogImpl)

at org.mortbay.log.LogImpl.message(LogImpl.java:399)

at org.mortbay.log.LogImpl.warn(LogImpl.java:548)

at org.mortbay.util.ThreadedServer.acceptSocket(ThreadedServer.java:449)

at org.mortbay.util.ThreadedServer$Acceptor.run(ThreadedServer.java:608)

“SocketListener0-1” prio=1 tid=0x08794150 nid=0x5bfa in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaae0e428> (a org.mortbay.util.ThreadPool$PoolThread)
    at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:522)
  • locked <0xaae0e428> (a org.mortbay.util.ThreadPool$PoolThread)

“SocketListener0-0” prio=1 tid=0x08670fc8 nid=0x5bf9 in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaae0e4a0> (a org.mortbay.util.ThreadPool$PoolThread)
    at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:522)
  • locked <0xaae0e4a0> (a org.mortbay.util.ThreadPool$PoolThread)

“Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=9090]” prio=1 tid=0x08626688 nid=0x5bf8 runnable

at java.net.PlainSocketImpl.socketAccept(Native Method)

at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)

  • locked <0xaae0e588> (a java.net.SocksSocketImpl)

at java.net.ServerSocket.implAccept(ServerSocket.java:450)

at java.net.ServerSocket.accept(ServerSocket.java:421)

at org.mortbay.util.ThreadedServer.acceptSocket(ThreadedServer.java:423)

at org.mortbay.util.ThreadedServer$Acceptor.run(ThreadedServer.java:608)

“SessionScavenger” daemon prio=1 tid=0x087bc218 nid=0x5bf6 waiting on condition

at java.lang.Thread.sleep(Native Method)

at org.mortbay.jetty.servlet.AbstractSessionManager$SessionScavenger.run(AbstractS essionManager.java:588)

“Rollover” daemon prio=1 tid=0x08289e38 nid=0x5bf5 waiting on condition

at java.lang.Thread.sleep(Native Method)

at org.mortbay.util.RolloverFileOutputStream$Rollover.run(RolloverFileOutputStream .java:302)

“DestroyJavaVM” prio=1 tid=0xa8b48ed0 nid=0x5bd8 waiting on condition

“pool-1-thread-1” prio=1 tid=0xa8b30450 nid=0x5bf4 waiting on condition

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

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

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

at java.util.concurrent.DelayQueue.take(DelayQueue.java:135)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Schedule dThreadPoolExecutor.java:504)

at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Schedule dThreadPoolExecutor.java:497)

at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)

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

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

“SocketSendingTracker” daemon prio=1 tid=0xa94f3420 nid=0x5bf3 in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaad06e10> (a org.jivesoftware.wildfire.net.SocketSendingTracker$1)
    at org.jivesoftware.wildfire.net.SocketSendingTracker$1.run(SocketSendingTracker.j ava:64)
  • locked <0xaad06e10> (a org.jivesoftware.wildfire.net.SocketSendingTracker$1)

“Socket Listener at port 5222” daemon prio=1 tid=0x08373580 nid=0x5bf0 runnable

at java.net.PlainSocketImpl.socketAccept(Native Method)

at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)

  • locked <0xaac7e840> (a java.net.SocksSocketImpl)

at java.net.ServerSocket.implAccept(ServerSocket.java:450)

at java.net.ServerSocket.accept(ServerSocket.java:421)

at org.jivesoftware.wildfire.net.SocketAcceptThread.run(SocketAcceptThread.java:12 5)

“Socket Listener at port 5269” daemon prio=1 tid=0x081f05e0 nid=0x5bef runnable

at java.net.PlainSocketImpl.socketAccept(Native Method)

at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)

  • locked <0xaac7e950> (a java.net.SocksSocketImpl)

at java.net.ServerSocket.implAccept(ServerSocket.java:450)

at java.net.ServerSocket.accept(ServerSocket.java:421)

at org.jivesoftware.wildfire.net.SocketAcceptThread.run(SocketAcceptThread.java:12 5)

“Auditor” prio=1 tid=0x081cd0d8 nid=0x5bee in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaac64d98> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:509)
  • locked <0xaac64d98> (a java.util.TaskQueue)

at java.util.TimerThread.run(Timer.java:462)

“MUC cleanup” prio=1 tid=0xa8b020b8 nid=0x5bed in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaac50828> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:509)
  • locked <0xaac50828> (a java.util.TaskQueue)

at java.util.TimerThread.run(Timer.java:462)

“Sessions cleanup” prio=1 tid=0xa9493e18 nid=0x5bec in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaac2c9a0> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:509)
  • locked <0xaac2c9a0> (a java.util.TaskQueue)

at java.util.TimerThread.run(Timer.java:462)

“Thread-2” daemon prio=1 tid=0xa94ef210 nid=0x5beb waiting on condition

at java.lang.Thread.sleep(Native Method)

at org.jivesoftware.database.ConnectionPool.run(ConnectionPool.java:370)

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

“Thread-0” daemon prio=1 tid=0xaa12a958 nid=0x5be2 waiting on condition

at java.lang.Thread.sleep(Native Method)

at com.install4j.runtime.Launcher$StopWatcherThread.run(Unknown Source)

“Low Memory Detector” daemon prio=1 tid=0xaa1038b0 nid=0x5be0 runnable

“CompilerThread1” daemon prio=1 tid=0xaa1024c8 nid=0x5bdf waiting on condition

“CompilerThread0” daemon prio=1 tid=0xaa101540 nid=0x5bde waiting on condition

“AdapterThread” daemon prio=1 tid=0xaa100578 nid=0x5bdd waiting on condition

“Signal Dispatcher” daemon prio=1 tid=0x080f0d40 nid=0x5bdc waiting on condition

“Finalizer” daemon prio=1 tid=0x080e8138 nid=0x5bdb in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaaba51c0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
  • locked <0xaaba51c0> (a java.lang.ref.ReferenceQueue$Lock)

at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)

at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

“Reference Handler” daemon prio=1 tid=0x080e6b60 nid=0x5bda in Object.wait()

at java.lang.Object.wait(Native Method)

  • waiting on <0xaaba5240> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:474)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
  • locked <0xaaba5240> (a java.lang.ref.Reference$Lock)

“VM Thread” prio=1 tid=0x080e46c8 nid=0x5bd9 runnable

“VM Periodic Task Thread” prio=1 tid=0xaa104e18 nid=0x5be1 waiting on condition

The problem on my box was a missing private key for a certificate. Not only had it consumed 100% CPU, but it did also write 58G into admin-console.log cough. Anyway I advise users of commercial certs who have theirs in OpenSSL format to look at pkeytool[1], which could import such keys into Java’'s keystore.

http://pkeytool.couchpotato.net/pkeytool/

Hi,

looking at the thread there is only one thing which made me wonder, it was that the SSL acceptor was writing to the log file and not listening like the normal connector. But as “LogImpl.java:548” was yet not compiled by JIT this did not look like a problem. Your post proved me wrong.

I don’'t have a linux tool to display the CPU cycles per thread (maybe the current “ps” command can do this), this would have been the next step.

So there’'s still the windows server, for windows http://www.codeproject.com/csharp/processescpuusage.asp allows to show the usage per thread. The “nid=0x5bfb” would there be displayed as “23547 - 99%”. Maybe damito can use this tool to identify the looping thread inside the JVM or provide a stack trace.

LG

//SSL

“Acceptor [SSL: ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=9091]]”

prio=1 tid=0xa8260e10 nid=0x5bfb runnable

at org.mortbay.log.LogImpl.warn(LogImpl.java:548)

at org.mortbay.util.ThreadedServer.acceptSocket(ThreadedServer.java:449)

at org.mortbay.util.ThreadedServer$Acceptor.run(ThreadedServer.java:608)

//normal one

“Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=9090]”

prio=1 tid=0x08626688 nid=0x5bf8 runnable

at java.net.PlainSocketImpl.socketAccept(Native Method)

/code

Same problem here : I have CentOS 4.2.

I also have a legal certificate for SSL.

Disabling SSL Admin (set 9091 to -1 in /opt/wildfire/conf/wildfire.xml) silenced the CPU leak.

I am using 2.5 btw.

Same change fixed a similar issue on SBS2003 for me.