glassfish
  1. glassfish
  2. GLASSFISH-18849

GlassFish CPU utilization is high sometimes after a broken pipe occurs

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.1.2
    • Fix Version/s: None
    • Component/s: grizzly-kernel
    • Labels:
      None

      Description

      Similar to GLASSFISH-18705, but in this case, compression isn't being used as in 18705. The patches provided for 18705 resolved the compression/ssl issue, but doesn't resolve this particular case.

      ---------------------------------

      In our case, the problem persists. In fact, the diagnosis has changed, but the prognosis is the same.
      Described at the end of this message, there are the three logs - [1], [2] and [3] - directly associated with the bug, which became a little rarer, but still occurs.

      The Glassfish's (3.1.2 patched) behaviour to enter on 'busy waiting' is detailed next:

      (a) Sometimes the exception [1] is logged on 'server.log', but Glassfish sometimes continue to run fine with no problem.
      (b) Sometimes after [1] occur, the log [3] starts to be written thousands of times on server.log, but apparently with no problem to the normal Glassfish's behaviour.
      (c) However, sometimes after [1], the exception [2] is throwed and logged. Generally [2] is logged imediattly after [1], but sometimes after some few minutes. When [2] is logged, one core enters in busy waiting.
      (d) The process (c) may repeat itself after some hours, but sometimes even after some several minutes, which means our application may be down at any time and we must restart the server usually each day or less.

      It is valid to noticed that the described behaviors (a-c) are different from the Glassfish 3.1.1 having no patch. When there is no patch on GF_3.1.1, the 'busy waiting' begins imediattly after [3].

      #######
      [LOG 1]
      #######
      [#|2012-06-25T17:43:44.472-0300|WARNING|glassfish3.1.2|javax.enterprise.system.container.web.com.sun.enterprise.web|_ThreadID=22;_ThreadName=Thread-2;|org.apache.catalina.core.StandardHostValve@6ac45da6: Exception processing ErrorPage[errorCode=404, location=/erro404.jsf]
      org.apache.catalina.connector.ClientAbortException: java.io.IOException: Connection reset by peer
      at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:384)
      at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:353)
      at org.apache.catalina.connector.Response.flushBuffer(Response.java:643)
      at org.apache.catalina.connector.ResponseFacade.flushBuffer(ResponseFacade.java:328)
      at org.apache.catalina.core.StandardHostValve.dispatchToErrorPage(StandardHostValve.java:671)
      at org.apache.catalina.core.StandardHostValve.status(StandardHostValve.java:357)
      at org.apache.catalina.core.StandardHostValve.postInvoke(StandardHostValve.java:221)
      at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:333)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
      at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
      at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
      at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:849)
      at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:746)
      at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1045)
      at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:228)
      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:662)
      Caused by: java.io.IOException: Connection reset by peer
      at sun.nio.ch.FileDispatcher.write0(Native Method)
      at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:29)
      at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:69)
      at sun.nio.ch.IOUtil.write(IOUtil.java:40)
      at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:334)
      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:417)
      at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:489)
      at com.sun.grizzly.http.SocketChannelOutputBuffer.flush(SocketChannelOutputBuffer.java:467)
      at com.sun.grizzly.http.ProcessorTask.action(ProcessorTask.java:1276)
      at com.sun.grizzly.tcp.Response.action(Response.java:268)
      at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:380)
      at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:353)
      at org.apache.catalina.connector.CoyoteWriter.flush(CoyoteWriter.java:153)
      at org.apache.catalina.core.ApplicationDispatcherForward.closeResponse(ApplicationDispatcherForward.java:407)
      at org.apache.catalina.core.ApplicationDispatcherForward.commit(ApplicationDispatcherForward.java:154)
      at org.apache.catalina.core.ApplicationDispatcher.dispatch(ApplicationDispatcher.java:358)
      at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:472)
      at org.apache.catalina.core.StandardHostValve.dispatchToErrorPage(StandardHostValve.java:669)
      ... 20 more

      #]

      #######
      [LOG 2]
      #######
      [#|2012-06-25T17:43:44.729-0300|SEVERE|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=22;_ThreadName=Thread-2;|java.io.IOException: Broken pipe
      at sun.nio.ch.FileDispatcher.write0(Native Method)
      at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:29)
      at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:69)
      at sun.nio.ch.IOUtil.write(IOUtil.java:40)
      at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:334)
      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:417)
      at com.sun.grizzly.http.SocketChannelOutputBuffer.flushBuffer(SocketChannelOutputBuffer.java:489)
      at com.sun.grizzly.http.SocketChannelOutputBuffer.realWriteBytes(SocketChannelOutputBuffer.java:373)
      at com.sun.grizzly.tcp.http11.InternalOutputBuffer$OutputStreamOutputBuffer.doWrite(InternalOutputBuffer.java:894)
      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:95)
      at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:140)
      at com.sun.grizzly.tcp.http11.filters.GzipOutputFilter.recycle(GzipOutputFilter.java:186)
      at com.sun.grizzly.http.SocketChannelOutputBuffer.recycle(SocketChannelOutputBuffer.java:510)
      at com.sun.grizzly.http.ProcessorTask.finishResponse(ProcessorTask.java:838)
      at com.sun.grizzly.http.ProcessorTask.postResponse(ProcessorTask.java:771)
      at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:747)
      at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1045)
      at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:228)
      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:662)

      #]

      #######
      [LOG 3]
      #######
      [#|2012-06-26T10:01:15.053-0300|WARNING|glassfish3.1.2|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=18;_ThreadName=Thread-2;|GRIZZLY0023: Interrupting idle Thread: http-thread-pool-8080(2).|#]

        Activity

        Hide
        Ryan Lubke added a comment -

        Closing.

        Show
        Ryan Lubke added a comment - Closing.
        Hide
        fabiosf added a comment -

        Hi, Ryan

        I checked as you requested.
        I took the md5sum from the two files involved on the patch, grizzly-utils.jar and (ii) grizzly-http.jar, on our server, and they matches with the md5sum of the same jars contained within "patch.jar".

        Please, take a look:

        md5sum /data/glassfish3/glassfish/modules/grizzly-utils.jar /data/glassfish3/glassfish/modules/grizzly-http.jar
        947b09d1da3993495fb4f060da90e7ca /data/glassfish3/glassfish/modules/grizzly-utils.jar
        247d5769ce5378a1169d786c5611763e /data/glassfish3/glassfish/modules/grizzly-http.jar

        Just to contrast, the original files, from the original GF_3.1.2, have the following md5sum:
        31663ed99c679106beb2970fa68cb904 grizzly-utils.jar
        fa6e7cb99f38e8c2208f02ac54b559e9 grizzly-http.jar

        Show
        fabiosf added a comment - Hi, Ryan I checked as you requested. I took the md5sum from the two files involved on the patch, grizzly-utils.jar and (ii) grizzly-http.jar, on our server, and they matches with the md5sum of the same jars contained within "patch.jar". Please, take a look: md5sum /data/glassfish3/glassfish/modules/grizzly-utils.jar /data/glassfish3/glassfish/modules/grizzly-http.jar 947b09d1da3993495fb4f060da90e7ca /data/glassfish3/glassfish/modules/grizzly-utils.jar 247d5769ce5378a1169d786c5611763e /data/glassfish3/glassfish/modules/grizzly-http.jar Just to contrast, the original files, from the original GF_3.1.2, have the following md5sum: 31663ed99c679106beb2970fa68cb904 grizzly-utils.jar fa6e7cb99f38e8c2208f02ac54b559e9 grizzly-http.jar

          People

          • Assignee:
            oleksiys
            Reporter:
            Ryan Lubke
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: