Glassfish - high CPU usge

Question

I'm using Glassfish 3.1.1 web profile in production envirnoment and it's eating too much CPU. Here is server settings: Windows Server 2008 R2 64bit, Intel Xeon 8core @ 3,2GHz, 8GB ram. I'm using JDK 1.7u2 64bit. Glassfish JVM settings:

<jvm-options>-XX:+UseCompressedOops</jvm-options>
<jvm-options>-Xmn1g</jvm-options>
<jvm-options>-Xss128k</jvm-options>
<jvm-options>-XX:+UseParallelOldGC</jvm-options>
<jvm-options>-XX:ParallelGCThreads=4</jvm-options>
<jvm-options>-Xmx3g</jvm-options>
<jvm-options>-XX:+DisableExplicitGC</jvm-options>
<jvm-options>-d64</jvm-options>
<jvm-options>-XX:PermSize=256m</jvm-options>
<jvm-options>-Xms3g</jvm-options>
<jvm-options>-XX:MaxPermSize=256m</jvm-options>
<jvm-options>-XX:+AggressiveHeap</jvm-options>

I've also tune some options according to http://jfarcand.wordpress.com/2009/11/27/putting-glassfish-v3-in-production-essential-surviving-guide/ Running for few hours or 1 day Glassfish use 15% to 40% CPU, someties 90% and application dosen't respond.

[#|2012-02-03T10:30:46.837+0100|WARNING|glassfish3.1.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=43;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-80(32).|#]

[#|2012-02-03T10:30:55.074+0100|WARNING|glassfish3.1.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=41;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-80(41).|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|java.nio.channels.ClosedChannelException
    at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:249)
    at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:440)
    at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:108)
    at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:76)
    at com.sun.grizzly.http.SocketChannelOutputBuffer.flushChannel(SocketChannelOutputBuffer.java:326)
    at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:398)
    at com.sun.grizzly.http.SocketChannelOutputBuffer.realWriteBytes(SocketChannelOutputBuffer.java:282)
    at com.sun.grizzly.tcp.http11.InternalOutputBuffer$OutputStreamOutputBuffer.doWrite(InternalOutputBuffer.java:898)
    at com.sun.grizzly.tcp.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOutputFilter.java:167)
    at com.sun.grizzly.tcp.http11.filters.GzipOutputFilter$FakeOutputStream.write(GzipOutputFilter.java:223)
    at java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:169)
    at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:238)
    at com.sun.grizzly.tcp.http11.filters.GzipOutputFilter.recycle(GzipOutputFilter.java:186)
    at com.sun.grizzly.http.SocketChannelOutputBuffer.recycle(SocketChannelOutputBuffer.java:417)
    at com.sun.grizzly.http.ProcessorTask.finishResponse(ProcessorTask.java:817)
    at com.sun.grizzly.http.ProcessorTask.postResponse(ProcessorTask.java:750)
    at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:726)
    at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1019)
    at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225)
    at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
    at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
    at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
    at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
    at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
    at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
    at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
    at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
    at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
    at java.lang.Thread.run(Thread.java:722)
|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:249)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:440)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:108)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.util.OutputWriter.flushChannel(OutputWriter.java:76)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.SocketChannelOutputBuffer.flushChannel(SocketChannelOutputBuffer.java:326)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:398)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.SocketChannelOutputBuffer.realWriteBytes(SocketChannelOutputBuffer.java:282)|#]

[#|2012-02-03T10:30:56.665+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.tcp.http11.InternalOutputBuffer$OutputStreamOutputBuffer.doWrite(InternalOutputBuffer.java:898)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.tcp.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOutputFilter.java:167)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.tcp.http11.filters.GzipOutputFilter$FakeOutputStream.write(GzipOutputFilter.java:223)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at java.util.zip.GZIPOutputStream.finish(GZIPOutputStream.java:169)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:238)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.tcp.http11.filters.GzipOutputFilter.recycle(GzipOutputFilter.java:186)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.SocketChannelOutputBuffer.recycle(SocketChannelOutputBuffer.java:417)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.ProcessorTask.finishResponse(ProcessorTask.java:817)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.ProcessorTask.postResponse(ProcessorTask.java:750)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:726)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1019)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.ContextTask.run(ContextTask.java:71)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)|#]

[#|2012-02-03T10:30:56.681+0100|SEVERE|glassfish3.1.1|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=138;_ThreadName=Thread-2;|    at java.lang.Thread.run(Thread.java:722)|#]

[#|2012-02-03T10:31:00.440+0100|WARNING|glassfish3.1.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=40;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-80(38).|#]

[#|2012-02-03T10:33:49.170+0100|WARNING|glassfish3.1.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=40;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-80(11).|#]

[#|2012-02-03T10:33:57.235+0100|WARNING|glassfish3.1.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=43;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-80(16).|#]

Edit: I solved the problem, there is bug in Glassfish gzip compression, so I turned it off. http://www.java.net/forum/topic/glassfish/glassfish/glassfish-301-gzip-problem-threads-apparently-spinning-100-cpu-use

Instead I would use this: http://www.servletsuite.com/servlets/gzipflt.htm to compress content.

Answer 1

This is apparently a bug in GlassFish 3.1.1 and 3.1.2. The JIRA issue for it contains patches which might help.