java.lang.IllegalStateException

There are no available Samebug tips for this exception. Do you have an idea how to solve this issue? A short tip would help users who saw this issue last week.

  • Appears to be a race condition that I can reproduce 100% after startup and see rarely thereafter. The error produced from Tomcat is: SEVERE: Error processing request java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [MUST_DISPATCH] I am using using: Tomcat 7.0.50 Spring 3.2.6 Spring Security 3.1.4 Java 7 The code looks like this: {code:java} @RequestMapping(value = "/ack", method = RequestMethod.POST, produces="application/json") @ResponseBody public DeferredResult<AckPageHttpResponse> ackPage() { DeferredResult<AckPageHttpResponse> deferredResponse = new DeferredResult<AckPageHttpResponse>( ackPageTimeout); doStuffInSeparateThread( deferredResponse); log.debug( "returning deferredResult"); return deferredResponse; } {code} //doStuffinSeparateThread() {code:java} ... System.out.println( "NO SLEEP"); log.debug( "setting result on deferred result."); result.setResult( response); ... {code} On startup, I see in the logs: 2014-01-16 11:37:05,290 [http-bio-18080-exec-1] DEBUG com.acme.controller.AsyncPageController - returning deferredResult NO SLEEP 2014-01-16 11:37:05,291 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:37:05,295 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] 2014-01-16 11:37:05,296 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@57898e4d] 2014-01-16 11:37:05,296 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing Jan 16, 2014 6:37:05 PM org.apache.coyote.http11.AbstractHttp11Processor process SEVERE: Error processing request java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [MUST_DISPATCH] at org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:227) at org.apache.coyote.http11.Http11Processor.actionInternal(Http11Processor.java:358) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:871) at org.apache.coyote.Request.action(Request.java:344) at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:92) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:140) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:313) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) Thereafter, most invocations return successfully and I see: 2014-01-16 11:38:14,034 [http-bio-18080-exec-2] DEBUG com.acme.controller.AsyncPageController - returning deferredResult 2014-01-16 11:38:14,035 [http-bio-18080-exec-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] NO SLEEP 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@5be50167] 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing I believe the key to the issue is when the "Concurrent handling starting for POST" message appears in the logs. On a fresh restart, there seems to be a few millisecond duration between returning the DeferredResult from the Controller, and this log appearing. If I add a sleep before returning this condition is not seen. {code:java} ... System.out.println( "SLEEPING 50ms..."); try { Thread.sleep( 50); } catch( Exception e) {} System.out.println( "WAKING...."); log.debug( "setting result on deferred result."); result.setResult( response); ... {code} 2014-01-16 11:44:53,904 [http-bio-18080-exec-1] DEBUG com.acme.controller.AsyncPageController - returning deferredResult SLEEPING 50ms... 2014-01-16 11:44:53,909 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] WAKING.... 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@65751f91] 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing
    via by Oliver Johansson,
  • Appears to be a race condition that I can reproduce 100% after startup and see rarely thereafter. The error produced from Tomcat is: SEVERE: Error processing request java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [MUST_DISPATCH] I am using using: Tomcat 7.0.50 Spring 3.2.6 Spring Security 3.1.4 Java 7 The code looks like this: {code:java} @RequestMapping(value = "/ack", method = RequestMethod.POST, produces="application/json") @ResponseBody public DeferredResult<AckPageHttpResponse> ackPage() { DeferredResult<AckPageHttpResponse> deferredResponse = new DeferredResult<AckPageHttpResponse>( ackPageTimeout); doStuffInSeparateThread( deferredResponse); log.debug( "returning deferredResult"); return deferredResponse; } {code} //doStuffinSeparateThread() {code:java} ... System.out.println( "NO SLEEP"); log.debug( "setting result on deferred result."); result.setResult( response); ... {code} On startup, I see in the logs: 2014-01-16 11:37:05,290 [http-bio-18080-exec-1] DEBUG com.acme.controller.AsyncPageController - returning deferredResult NO SLEEP 2014-01-16 11:37:05,291 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:37:05,295 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] 2014-01-16 11:37:05,296 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@57898e4d] 2014-01-16 11:37:05,296 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing Jan 16, 2014 6:37:05 PM org.apache.coyote.http11.AbstractHttp11Processor process SEVERE: Error processing request java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [MUST_DISPATCH] at org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:227) at org.apache.coyote.http11.Http11Processor.actionInternal(Http11Processor.java:358) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:871) at org.apache.coyote.Request.action(Request.java:344) at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:92) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:140) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:313) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722) Thereafter, most invocations return successfully and I see: 2014-01-16 11:38:14,034 [http-bio-18080-exec-2] DEBUG com.acme.controller.AsyncPageController - returning deferredResult 2014-01-16 11:38:14,035 [http-bio-18080-exec-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] NO SLEEP 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@5be50167] 2014-01-16 11:38:14,035 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing I believe the key to the issue is when the "Concurrent handling starting for POST" message appears in the logs. On a fresh restart, there seems to be a few millisecond duration between returning the DeferredResult from the Controller, and this log appearing. If I add a sleep before returning this condition is not seen. {code:java} ... System.out.println( "SLEEPING 50ms..."); try { Thread.sleep( 50); } catch( Exception e) {} System.out.println( "WAKING...."); log.debug( "setting result on deferred result."); result.setResult( response); ... {code} 2014-01-16 11:44:53,904 [http-bio-18080-exec-1] DEBUG com.acme.controller.AsyncPageController - returning deferredResult SLEEPING 50ms... 2014-01-16 11:44:53,909 [http-bio-18080-exec-1] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent handling starting for POST [/page/ack] WAKING.... 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG com.acme.handler.HttpHandlerContext - setting result on deferred result. 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Concurrent result value [com.acme.controller.response.AckPageHttpResponse@65751f91] 2014-01-16 11:44:53,957 [ringBuffer-ringbuffer-2] DEBUG org.springframework.web.context.request.async.WebAsyncManager - Dispatching request to resume processing
    via by Oliver Johansson,
  • Tomcat 7 + Servlet 3.0 + cometD
    via by Juriy,
    • java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a request with Async state [MUST_DISPATCH] at org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:227) at org.apache.coyote.http11.Http11Processor.actionInternal(Http11Processor.java:358) at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:871) at org.apache.coyote.Request.action(Request.java:344) at org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:92) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:140) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:313) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)
    No Bugmate found.