glassfish
  1. glassfish
  2. GLASSFISH-20665

Grizzly generates a http 500 with simple index.html request under load / (maybe Grizzly closes the clients half-closed Sockets)

    Details

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

      Debian Linux

      Description

      I'm seeing 500 in my production monitoring.
      The test there is just requesting

      "GET / HTTP/1.0 \nUser-Agent:LogicMonitor\nConnection: close\n\n"
      

      After this implemented a small bash test:

      #!/bin/bash
      while [ 1 ]; do
      d=$(date +'%Y-%m-%d-%H:%M:%S-%N')
      echo $d
      curl -o testin.txt --connect-timeout 65 --max-time 60 "myhost?$d"
      if grep -q copyright "testin.txt"; then
      date
      echo "Found"
      rm testin.txt
      else
      date
      echo "Not Found"
      exit
      fi
      sleep 1
      done
      This exits every couple of minutes with "Not Found".
      

      With higher load this happens faster.

      On my testing platform I don't see this issue.

      Same application on Jetty(comparable load)
      -with a thread pool of 2000, but it's peeking only on 100 concurrent threads, so load should no be the issue -
      doesn't show those http 500s.

      I think both tests are http 1.0.

      With a patch (https://www.java.net/forum/topic/glassfish/glassfish/glassfish-v4-sends-sometimes-empty-response-curl-o-testintxt-myservercom-under-load-accesslog-sh) for grizzly logging I got:

      2013-06-26T09:52:07.724+0200] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=107 _ThreadName=http-listener-1(88)] [timeMillis: 1372233127724] [levelValue: 900] [[
        StandardWrapperValve[show]: Servlet.service() for servlet show threw exception
      java.io.IOException: Connection closed
              at org.glassfish.grizzly.asyncqueue.TaskQueue.onClose(TaskQueue.java:302)
              at org.glassfish.grizzly.nio.AbstractNIOAsyncQueueWriter.onClose(AbstractNIOAsyncQueueWriter.java:591)
              at org.glassfish.grizzly.nio.transport.TCPNIOTransport.closeConnection(TCPNIOTransport.java:611)
              at org.glassfish.grizzly.nio.NIOConnection$2.run(NIOConnection.java:438)
              at org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask.run(DefaultSelectorHandler.java:487)
              at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTaskQueue(DefaultSelectorHandler.java:293)
              at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTasks(DefaultSelectorHandler.java:284)
              at org.glassfish.grizzly.nio.DefaultSelectorHandler.preSelect(DefaultSelectorHandler.java:100)
              at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:329)
              at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:274)
              at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
              at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
              at java.lang.Thread.run(Thread.java:722)
      Caused by: java.lang.Exception: Close stack trace
              at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:425)
              at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:291)
              at org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:938)
              at org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTransportFilter.java:75)
              at org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.java:173)
              at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
              at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
              at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
              at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
              at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
              at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
              at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
              at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
              at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
              at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
              at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
              ... 3 more
      ]]
      

      In the forum oleksiys said:

      I think the client closes a Socket output (makes the Socket half-closed) and the server, in response, closes the Socket completely, when there is still some data to be written.

        Activity

        iceandfire created issue -
        Hide
        oleksiys added a comment -

        can you pls. try this patch
        https://dl.dropboxusercontent.com/u/7319744/nucleus-grizzly-all.jar

        you'll get larger exception this time

        thank you in advance.

        Show
        oleksiys added a comment - can you pls. try this patch https://dl.dropboxusercontent.com/u/7319744/nucleus-grizzly-all.jar you'll get larger exception this time thank you in advance.
        Hide
        iceandfire added a comment -

        Hi I have installed the new patch:

        [2013-06-27T08:48:41.578+0200] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=185 _ThreadName=http-listener-1(166)] [timeMillis: 1372315721578] [levelValue: 900] [[
          StandardWrapperValve[default]: Servlet.service() for servlet default threw exception
        java.io.IOException: I/O error occurred
                at org.glassfish.grizzly.http.io.OutputBuffer.handleAsyncErrors(OutputBuffer.java:917)
                at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:648)
                at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355)
                at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342)
                at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161)
                at org.apache.catalina.servlets.DefaultServlet.copy(DefaultServlet.java:2069)
                at org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:1092)
                at org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:518)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
                at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
                at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318)
                at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
                at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
                at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
                at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
                at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
                at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:354)
                at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
                at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
                at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
                at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
                at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
                at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
                at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
                at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
                at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
                at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
                at java.lang.Thread.run(Thread.java:722)
        Caused by: java.io.IOException: Connection closed
                at org.glassfish.grizzly.asyncqueue.TaskQueue.onClose(TaskQueue.java:302)
                at org.glassfish.grizzly.nio.AbstractNIOAsyncQueueWriter.onClose(AbstractNIOAsyncQueueWriter.java:591)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.closeConnection(TCPNIOTransport.java:611)
                at org.glassfish.grizzly.nio.NIOConnection$2.run(NIOConnection.java:438)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask.run(DefaultSelectorHandler.java:487)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTaskQueue(DefaultSelectorHandler.java:293)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTasks(DefaultSelectorHandler.java:284)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.preSelect(DefaultSelectorHandler.java:100)
                at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:329)
                at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:274)
                ... 3 more
        Caused by: java.lang.Exception: Close stack trace
                at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:425)
                at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:291)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:938)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTransportFilter.java:75)
                at org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.java:173)
                at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
                at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
                at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
                ... 3 more
        ]]
        
        Show
        iceandfire added a comment - Hi I have installed the new patch: [2013-06-27T08:48:41.578+0200] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=185 _ThreadName=http-listener-1(166)] [timeMillis: 1372315721578] [levelValue: 900] [[ StandardWrapperValve[ default ]: Servlet.service() for servlet default threw exception java.io.IOException: I/O error occurred at org.glassfish.grizzly.http.io.OutputBuffer.handleAsyncErrors(OutputBuffer.java:917) at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:648) at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355) at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342) at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161) at org.apache.catalina.servlets.DefaultServlet.copy(DefaultServlet.java:2069) at org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:1092) at org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:518) at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673) at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673) at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:354) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260) at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188) at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191) at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168) at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544) at java.lang. Thread .run( Thread .java:722) Caused by: java.io.IOException: Connection closed at org.glassfish.grizzly.asyncqueue.TaskQueue.onClose(TaskQueue.java:302) at org.glassfish.grizzly.nio.AbstractNIOAsyncQueueWriter.onClose(AbstractNIOAsyncQueueWriter.java:591) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.closeConnection(TCPNIOTransport.java:611) at org.glassfish.grizzly.nio.NIOConnection$2.run(NIOConnection.java:438) at org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask.run(DefaultSelectorHandler.java:487) at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTaskQueue(DefaultSelectorHandler.java:293) at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTasks(DefaultSelectorHandler.java:284) at org.glassfish.grizzly.nio.DefaultSelectorHandler.preSelect(DefaultSelectorHandler.java:100) at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:329) at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:274) ... 3 more Caused by: java.lang.Exception: Close stack trace at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:425) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:291) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:938) at org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTransportFilter.java:75) at org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.java:173) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) ... 3 more ]]
        Hide
        oleksiys added a comment -

        Thank you for the stacktrace.
        I've updated the patch (at the same location), will appreciate if you can try it.

        I have couple of questions also

        1) Are you using asynchronous Servlet 3.0/3.1 features, like startAsync() or may be non-blocking API introduced in Servlet 3.1?
        2) Are you able to reproduce the same problem with zero load, when only the script is running, nothing else?
        3) If 2) is negative, are you able to reproduce the problem when you load the server by requesting very simple Servlet (not the one you use in production)?

        Thank you in advance.

        Show
        oleksiys added a comment - Thank you for the stacktrace. I've updated the patch (at the same location), will appreciate if you can try it. I have couple of questions also 1) Are you using asynchronous Servlet 3.0/3.1 features, like startAsync() or may be non-blocking API introduced in Servlet 3.1? 2) Are you able to reproduce the same problem with zero load, when only the script is running, nothing else? 3) If 2) is negative, are you able to reproduce the problem when you load the server by requesting very simple Servlet (not the one you use in production)? Thank you in advance.
        Hide
        iceandfire added a comment -

        New Patch:

        [2013-06-28T14:34:53.057+0200] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=160 _ThreadName=http-listener-1(141)] [timeMillis: 1372422893057] [levelValue: 900] [[
          StandardWrapperValve[default]: Servlet.service() for servlet default threw exception
        java.io.IOException: I/O error occurred
                at org.glassfish.grizzly.http.io.OutputBuffer.handleAsyncErrors(OutputBuffer.java:917)
                at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:648)
                at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355)
                at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342)
                at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161)
                at org.apache.catalina.servlets.DefaultServlet.copy(DefaultServlet.java:2069)
                at org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:1092)
                at org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:518)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
                at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
                at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
                at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318)
                at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
                at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
                at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
                at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
                at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
                at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
                at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:354)
                at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
                at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
                at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
                at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
                at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
                at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
                at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
                at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
                at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
                at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
                at java.lang.Thread.run(Thread.java:722)
        Caused by: java.io.IOException: Connection closed [Thread[http-listener-1-kernel(5) SelectorRunner,5,main]]
                at org.glassfish.grizzly.asyncqueue.TaskQueue.onClose(TaskQueue.java:302)
                at org.glassfish.grizzly.nio.AbstractNIOAsyncQueueWriter.onClose(AbstractNIOAsyncQueueWriter.java:591)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.closeConnection(TCPNIOTransport.java:611)
                at org.glassfish.grizzly.nio.NIOConnection$2.run(NIOConnection.java:441)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask.run(DefaultSelectorHandler.java:487)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTaskQueue(DefaultSelectorHandler.java:293)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTasks(DefaultSelectorHandler.java:284)
                at org.glassfish.grizzly.nio.DefaultSelectorHandler.preSelect(DefaultSelectorHandler.java:100)
                at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:329)
                at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:274)
                ... 3 more
        Caused by: java.lang.Exception: Close stack trace [Thread[http-listener-1(160),5,main]]
                at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:426)
                at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:291)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:938)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTransportFilter.java:75)
                at org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.java:173)
                at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
                at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
                at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
                at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
                at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
                at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
                ... 3 more
        Caused by: java.lang.Exception: Last OP_READ enabled stack trace [Thread[http-listener-1(141),5,main]]
                at org.glassfish.grizzly.nio.NIOConnection.enableIOEvent(NIOConnection.java:721)
                at org.glassfish.grizzly.strategies.AbstractIOStrategy$EnableInterestProcessingHandler.onComplete(AbstractIOStrategy.java:141)
                at org.glassfish.grizzly.ProcessorExecutor.complete(ProcessorExecutor.java:117)
                at org.glassfish.grizzly.ProcessorExecutor.complete0(ProcessorExecutor.java:219)
                at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:86)
                ... 8 more
        
        Show
        iceandfire added a comment - New Patch: [2013-06-28T14:34:53.057+0200] [glassfish 4.0] [WARNING] [] [javax.enterprise.web] [tid: _ThreadID=160 _ThreadName=http-listener-1(141)] [timeMillis: 1372422893057] [levelValue: 900] [[ StandardWrapperValve[ default ]: Servlet.service() for servlet default threw exception java.io.IOException: I/O error occurred at org.glassfish.grizzly.http.io.OutputBuffer.handleAsyncErrors(OutputBuffer.java:917) at org.glassfish.grizzly.http.io.OutputBuffer.write(OutputBuffer.java:648) at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:355) at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:342) at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:161) at org.apache.catalina.servlets.DefaultServlet.copy(DefaultServlet.java:2069) at org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:1092) at org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:518) at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673) at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174) at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734) at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673) at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:354) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260) at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188) at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191) at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168) at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544) at java.lang. Thread .run( Thread .java:722) Caused by: java.io.IOException: Connection closed [ Thread [http-listener-1-kernel(5) SelectorRunner,5,main]] at org.glassfish.grizzly.asyncqueue.TaskQueue.onClose(TaskQueue.java:302) at org.glassfish.grizzly.nio.AbstractNIOAsyncQueueWriter.onClose(AbstractNIOAsyncQueueWriter.java:591) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.closeConnection(TCPNIOTransport.java:611) at org.glassfish.grizzly.nio.NIOConnection$2.run(NIOConnection.java:441) at org.glassfish.grizzly.nio.DefaultSelectorHandler$RunnableTask.run(DefaultSelectorHandler.java:487) at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTaskQueue(DefaultSelectorHandler.java:293) at org.glassfish.grizzly.nio.DefaultSelectorHandler.processPendingTasks(DefaultSelectorHandler.java:284) at org.glassfish.grizzly.nio.DefaultSelectorHandler.preSelect(DefaultSelectorHandler.java:100) at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:329) at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:274) ... 3 more Caused by: java.lang.Exception: Close stack trace [ Thread [http-listener-1(160),5,main]] at org.glassfish.grizzly.nio.NIOConnection.close0(NIOConnection.java:426) at org.glassfish.grizzly.nio.transport.TCPNIOConnection.close0(TCPNIOConnection.java:291) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.read(TCPNIOTransport.java:938) at org.glassfish.grizzly.nio.transport.TCPNIOTransportFilter.handleRead(TCPNIOTransportFilter.java:75) at org.glassfish.grizzly.filterchain.TransportFilter.handleRead(TransportFilter.java:173) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135) ... 3 more Caused by: java.lang.Exception: Last OP_READ enabled stack trace [ Thread [http-listener-1(141),5,main]] at org.glassfish.grizzly.nio.NIOConnection.enableIOEvent(NIOConnection.java:721) at org.glassfish.grizzly.strategies.AbstractIOStrategy$EnableInterestProcessingHandler.onComplete(AbstractIOStrategy.java:141) at org.glassfish.grizzly.ProcessorExecutor.complete(ProcessorExecutor.java:117) at org.glassfish.grizzly.ProcessorExecutor.complete0(ProcessorExecutor.java:219) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:86) ... 8 more
        Hide
        iceandfire added a comment -

        1) Are you using asynchronous Servlet 3.0/3.1 features, like startAsync() or may be non-blocking API introduced in Servlet 3.1?
        No, what I'm using is:

        ReentrantLock lock = null;
        synchronized (this.getClass())
        {
        	lock = (ReentrantLock) lockCache.getElement(userId);
        	if (lock == null)
                lock = new ReentrantLock();
        	lockCache.addElement(fullId, lock);
        }
        
        lock.lock();
        try
        {
        ...
        

        2) Are you able to reproduce the same problem with zero load, when only the script is running, nothing else?
        => NO
        3) If 2) is negative, are you able to reproduce the problem when you load the server by requesting very simple Servlet (not the one you use in production)?
        => Going to try out

        Show
        iceandfire added a comment - 1) Are you using asynchronous Servlet 3.0/3.1 features, like startAsync() or may be non-blocking API introduced in Servlet 3.1? No, what I'm using is: ReentrantLock lock = null ; synchronized ( this .getClass()) { lock = (ReentrantLock) lockCache.getElement(userId); if (lock == null ) lock = new ReentrantLock(); lockCache.addElement(fullId, lock); } lock.lock(); try { ... 2) Are you able to reproduce the same problem with zero load, when only the script is running, nothing else? => NO 3) If 2) is negative, are you able to reproduce the problem when you load the server by requesting very simple Servlet (not the one you use in production)? => Going to try out
        Hide
        oleksiys added a comment -

        If it would be easier for you - you can share the complete servlet code, or send it to me directly to (oleksiys [at] java.net).
        What you're doing w/ locks is totally ok, don't see any problem there, but may be there is something else.

        thank you in advance.

        Show
        oleksiys added a comment - If it would be easier for you - you can share the complete servlet code, or send it to me directly to (oleksiys [at] java.net). What you're doing w/ locks is totally ok, don't see any problem there, but may be there is something else. thank you in advance.
        Hide
        oleksiys added a comment -

        Pls. disregard my previous comment.
        I think I found the problem, can you pls. try new patch (at the same location)?

        Thank you in advance.

        Show
        oleksiys added a comment - Pls. disregard my previous comment. I think I found the problem, can you pls. try new patch (at the same location)? Thank you in advance.
        Hide
        iceandfire added a comment -

        I think the last patch solved the issue.
        My basic test doesn't show errors anymore.

        What was changed?

        Show
        iceandfire added a comment - I think the last patch solved the issue. My basic test doesn't show errors anymore. What was changed?
        Hide
        oleksiys added a comment -

        It was a problem in Grizzly.
        When HTTP client doesn't read off an entire response and closes the connection - the error, which appears on server side may be propagated to a wrong request/response.

        It will be fixed in Grizzly 2.3.4

        Show
        oleksiys added a comment - It was a problem in Grizzly. When HTTP client doesn't read off an entire response and closes the connection - the error, which appears on server side may be propagated to a wrong request/response. It will be fixed in Grizzly 2.3.4
        oleksiys made changes -
        Field Original Value New Value
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s 4.0.1 [ 16061 ]
        Resolution Fixed [ 1 ]
        Hide
        oleksiys added a comment -

        for the records, this issue corresponds to GRIZZLY-1536

        Show
        oleksiys added a comment - for the records, this issue corresponds to GRIZZLY-1536
        Romain Grécourt made changes -
        Fix Version/s 4.1 [ 16387 ]
        Fix Version/s 4.0.1 [ 16061 ]

          People

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

            Dates

            • Created:
              Updated:
              Resolved: