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

        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
        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

          People

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

            Dates

            • Created:
              Updated:
              Resolved: