Bug 51630 - java.lang.IllegalStateException: Calling [asyncComplete()]
Summary: java.lang.IllegalStateException: Calling [asyncComplete()]
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 7
Classification: Unclassified
Component: Examples (show other bugs)
Version: 7.0.22
Hardware: PC Windows XP
: P2 normal (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-08-07 02:34 UTC by zhh
Modified: 2011-10-03 19:55 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description zhh 2011-08-07 02:34:08 UTC
example:

webapps\examples\WEB-INF\classes\async\Async0.java


log file: logs\localhost.2011-08-07.log
=============================================
java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [DISPATCHED]
	at org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:221)
	at org.apache.coyote.http11.Http11Processor.actionInternal(Http11Processor.java:525)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:773)
	at org.apache.coyote.Request.action(Request.java:344)
	at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:89)
	at async.Async0.service(Async0.java:42)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:684)
	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:593)
	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:530)
	at org.apache.catalina.core.AsyncContextImpl$1.run(AsyncContextImpl.java:173)
	at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:314)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:462)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:164)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:851)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:296)
	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1220)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:511)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:302)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:619)
Comment 1 Mark Thomas 2011-08-07 10:32:55 UTC
I see no such exception running the latest 7.0.x code.
Comment 2 zhh 2011-08-08 00:33:49 UTC
(In reply to comment #1)
> I see no such exception running the latest 7.0.x code.

I using the 7.0.19 code.

The IllegalStateException not showed in the browser, 
but in the Tomcat/logs/localhost.2011-08-07.log
Comment 3 Konstantin Kolinko 2011-10-03 11:10:10 UTC
Observing this as well with current trunk@r1178371 (7.0.22) using Nio connector.
WinXP 32-bit, JDK 6u26.

Steps to reproduce:
1. Configure Tomcat with org.apache.coyote.http11.Http11NioProtocol
I also have logging configured with OneLineFormatter, but that should not matter.

2. Start it and open in web browser the following page:
http://localhost:8080/examples/async/async0

3. The following exception is in localhost.<date>.log: (not in catalina*.log !)

03-окт-2011 14:35:15.218 SEVERE [http-nio-8080-exec-2] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [async0] in context with path [/examples] threw exception [java.lang.RuntimeException: java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [DISPATCHED]] with root cause
 java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [DISPATCHED]
	at org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:221)
	at org.apache.coyote.http11.Http11NioProcessor.actionInternal(Http11NioProcessor.java:476)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:807)
	at org.apache.coyote.Request.action(Request.java:344)
	at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:89)
	at async.Async0.service(Async0.java:42)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:684)
	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:593)
	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:530)
	at org.apache.catalina.core.AsyncContextImpl$1.run(AsyncContextImpl.java:173)
	at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:314)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:296)
	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1486)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:511)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1554)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)

In catalina.<date>.log one can see debug messages from Async0 servlet:
03-окт-2011 14:35:15.218 INFO [http-nio-8080-exec-2] async.Async0.service Received dispatch, completing on the worker thread.
03-окт-2011 14:35:15.218 INFO [http-nio-8080-exec-2] async.Async0.service After complete called started:false

What bothers me is that Async0 servlet is not annotated with @WebServlet(asyncSupported=true) as required by ch.2.3.3.3 of servlet-3_0-final-spec.pdf.  Page #12 (34/230) there: "It is illegal to call startAsync if the request is within the scope of a servlet or filter that does not support asynchronous operations"

The same chapter describes "isAsyncStarted()" saying that it should return false after a dispatch call. That is what we are observing here.

From description of "complete()" in the same chapter, it is container's responsibility to call complete() after service() method exits: "The complete method can be invoked by the container if
the request is dispatched to a servlet that does not support async processing, or
the target servlet called by AsyncContext.dispatch does not do a
subsequent call to startAsync. In this case, it is the container's responsibility
to call complete() as soon as that servlet's service method is exited."


So I think the IllegalStateException is valid here, but the Async0 example should be fixed by removing the complete() call and annotating the servlet with @WebServlet(asyncSupported=true).
Comment 4 Mark Thomas 2011-10-03 17:14:21 UTC
(In reply to comment #3)
> What bothers me is that Async0 servlet is not annotated with
> @WebServlet(asyncSupported=true) as required by ch.2.3.3.3 of
> servlet-3_0-final-spec.pdf.  Page #12 (34/230) there: "It is illegal to call
> startAsync if the request is within the scope of a servlet or filter that does
> not support asynchronous operations"

You can also set async support in web.xml and this is what is done for the examples.
Comment 5 Mark Thomas 2011-10-03 19:55:14 UTC
Fixed in trunk and 7.0.x and will be included in 7.0.23 onwards.