Bug 61932 - IllegalStateException when calling asyncContext.dispatch() in a non container thread with ReadListener used
Summary: IllegalStateException when calling asyncContext.dispatch() in a non container...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 8
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 8.5.24
Hardware: PC Mac OS X 10.1
: P2 normal (vote)
Target Milestone: ----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-12-27 07:36 UTC by Daniel Qian
Modified: 2018-01-04 01:44 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Qian 2017-12-27 07:36:57 UTC
Tomcat throws below exception when I use ReadListener and call AsyncContext.dispatch("/url") in another thread.

Dec 27, 2017 3:35:46 PM org.apache.coyote.AbstractProtocol$ConnectionHandler process
严重: Error reading request, ignored
java.lang.IllegalStateException: Calling [asyncOperation()] is not valid for a request with Async state [DISPATCHING]
	at org.apache.coyote.AsyncStateMachine.asyncOperation(AsyncStateMachine.java:253)
	at org.apache.coyote.AbstractProcessor.dispatchNonBlockingRead(AbstractProcessor.java:505)
	at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:200)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

Dec 27, 2017 3:35:46 PM org.apache.catalina.connector.CoyoteAdapter checkRecycled
信息: Encountered a non-recycled request and recycled it forcedly.
org.apache.catalina.connector.CoyoteAdapter$RecycleRequiredException
	at org.apache.catalina.connector.CoyoteAdapter.checkRecycled(CoyoteAdapter.java:501)
	at org.apache.coyote.http11.Http11Processor.recycle(Http11Processor.java:1707)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:972)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:940)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

Below is the code for reproducing the bug:


@WebServlet(value = "/async-read2", asyncSupported = true)
public class AsyncReadServlet2 extends HttpServlet {

  @Override
  protected void doPost(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {

    AsyncContext asyncCtx = req.startAsync();
    ServletInputStream is = req.getInputStream();
    is.setReadListener(new ReadListener() {

      @Override
      public void onDataAvailable() {

        try {
          byte buffer[] = new byte[1 * 1024];
          while (is.isReady() && !is.isFinished()) {
            int length = is.read(buffer);
            if (length == -1 && is.isFinished()) {
              return;
            }

          }

        } catch (IOException ex) {
          ex.printStackTrace();
        }
      }

      @Override
      public void onAllDataRead() {
      }

      @Override
      public void onError(Throwable t) {
      }
    });

    new Thread(() -> {
      try {
        Thread.sleep(10000L);
      } catch (InterruptedException e) {
        e.printStackTrace();
      }
      asyncCtx.dispatch("/error");
    }).start();

  }

}
Comment 1 Mark Thomas 2018-01-03 14:15:33 UTC
I'm planning on taking a look at this today. Does the client need to do anything to trigger this or is a simple POST sufficient? I'll try the simple POST but if there is more to it it would be helpful to know what that is.
Comment 2 Mark Thomas 2018-01-03 20:55:57 UTC
Thanks for the report and the test case. Bug reports are so much easier to work with when good test cases like this one are provided.

I adapted the provided Servlet into a Tomcat test case. The main change was to fix the potential timing issues (some of our CI systems can be randomly slow during test runs) by using a latch to trigger the dispatch rather than a fixed wait time.

There was a Tomcat bug here that I have fixed.

Fixed in:
- trunk for 9.0.3 onwards
- 8.5.x for 8.5.25 onwards
- 8.0.x for 8.0.49 onwards

7.0.x was not affected as Servlet 3.0 does not support non-blocking I/O.
Comment 3 Daniel Qian 2018-01-04 01:44:54 UTC
(In reply to Mark Thomas from comment #1)
> I'm planning on taking a look at this today. Does the client need to do
> anything to trigger this or is a simple POST sufficient? I'll try the simple
> POST but if there is more to it it would be helpful to know what that is.

Yes, I missed mention that I used a curl command with slow speed simulation:

curl -X POST -F "bigfile=@somefile" --limit-rate 5k http://localhost:8080/async-read2