You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by "Steffen Heil (Mailinglisten)" <li...@steffen-heil.de> on 2015/08/25 18:05:53 UTC

Exception using Async Servlet

Hi


I am using servlets with startAsync to be able to read and write asynchronously.
However from time to time the following is logged:

Aug 25, 2015 5:52:32 PM org.apache.catalina.connector.CoyoteAdapter asyncDispatch
SCHWERWIEGEND: Exception while processing an asynchronous request
java.lang.IllegalStateException: Calling [asyncError()] is not valid for a request with Async state [MUST_COMPLETE]
	at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:348)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:820)
	at org.apache.coyote.Request.action(Request.java:378)
	at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:406)
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:332)
	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1709)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:649)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1527)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1484)
	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:745)

There is no code of our own involved so I am wondering if my configuration is invalid or I am using the servlet in an incorrect way.
I would post some of the code we use here, but it is not really small, so where would I need to start searching or posting?


Regards,
  Steffen


Re: Exception using Async Servlet

Posted by Sean Dawson <se...@gmail.com>.
On Wed, Aug 26, 2015 at 8:13 AM, Steffen Heil (Mailinglisten) <
lists@steffen-heil.de> wrote:

> Hi
>
>
> Doing a lot of additional testing, I found the reason for the exception.
> In the "WriteListener.onError(Throwable)" handler, we released all our
> resources using a central function that included calling
> "context.complete()".
>
> It seems like tomcat does not like that call.
> However there are only two cases:
>
> 1. That call is NOT allowed in onError, then it should throw an exception
> right away.
> 2. That call IS allowed in onError, then it should not leave some internal
> inconsistency (as the later exception implies).
>
> BTW:
> 1. Calling "context.complete()" in "AsyncListener.onError(AsyncEvent)"
> seems not to be a problem.
> 2. The exception also prevents a call to
> "AsyncListener.onError(AsyncEvent)", so a WriteListener can hide the end of
> the connection completely from the AsyncListener. However to my understand
> those should be to separate state machines...
>
>
> Doing these tests, I recognized I did a lot of guessing about the
> interactions between the 3 different callbacks.
> Is there any documentation on how they interact?
>
>
I'd love to know this too...

http://stackoverflow.com/questions/29135237/asynccontext-timeouts-and-retries


>
> Regards,
>   Steffen
>
>
>
> > -----Ursprüngliche Nachricht-----
> > Von: Steffen Heil (Mailinglisten) [mailto:lists@steffen-heil.de]
> > Gesendet: Mittwoch, 26. August 2015 10:04
> > An: Tomcat Users List <us...@tomcat.apache.org>
> > Betreff: AW: Exception using Async Servlet
> >
> > Hi
> >
> >
> > > Make sure you are using the latest 8.0.26 release. There have been
> some fixes around async dispatch. If you still see the issue then
> > > we'll need a test case (as simple as possible) that reproduces the
> issue for us to investigate.
> >
> > I just upgraded to 8.0.26. But I see the same exception again:
> >
> > Aug 26, 2015 9:42:41 AM org.apache.catalina.connector.CoyoteAdapter
> asyncDispatch
> > SCHWERWIEGEND: Exception while processing an asynchronous request
> > java.lang.IllegalStateException: Calling [asyncError()] is not valid for
> a request with Async state [MUST_COMPLETE]
> >       at
> org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:351)
> >       at
> org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:820)
> >       at org.apache.coyote.Request.action(Request.java:378)
> >       at
> org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:419)
> >       at
> org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:332)
> >       at
> org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1709)
> >       at
> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:649)
> >       at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1526)
> >       at
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1482)
> >       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:745)
> >
> >
> > I *think* this happens in the following case:
> >
> > 1. A client opens an html file using https that gets dispatched to an
> Async servlet.
> >
> > 2. The servlet calls startAsync, registers read/write/context handlers:
> >       AsyncContext context = request.startAsync();
> >       context.setTimeout( 0 );
> >       ServletInputStream input = request.getInputStream();
> >       ServletOutputStream output = response.getOutputStream();
> >       ChannelProcessor processor = new ChannelProcessor( ... );
> >       context.addListener( processor );
> >       input.setReadListener( processor );
> >       output.setWriteListener( processor );
> >
> > 3. The server writes some data to "output".
> > 4. As the client is not sending data, "onAllDataRead" is called and the
> reference to "input" is dropped.
> > 5. "onWritePossible" is called, but there is no more data to send for
> now.
> > 6. The client window is closed. (BTW: The servlet is not notified about
> that at all.)
> > 7. Later, an server event occurs and the server writes to "output" again
> (after checking "isReady").
> >
> > I think this is the point, the exception is logged.
> >
> >
> > I will try to create a testcase, but stripping down that code is far
> from easy as it is in the middle of a framework.
> >
> >
> > I would also like to increase logging in tomcat, but I could not find
> out, how to do so.
> > My current logging.properties consists of the following only:
> >
> >
> > handlers = java.util.logging.ConsoleHandler
> > .handlers = java.util.logging.ConsoleHandler
> >
> > .level = TRACE
> > org.apache.level = TRACE
> >
> >
> > I suspect that should set any logger to TRACE, but only a few lines are
> logged...
> >
> >
> > Regards,
> >   Steffen
>
>

AW: Exception using Async Servlet

Posted by "Steffen Heil (Mailinglisten)" <li...@steffen-heil.de>.
Hi


Doing a lot of additional testing, I found the reason for the exception.
In the "WriteListener.onError(Throwable)" handler, we released all our resources using a central function that included calling "context.complete()".

It seems like tomcat does not like that call.
However there are only two cases:

1. That call is NOT allowed in onError, then it should throw an exception right away.
2. That call IS allowed in onError, then it should not leave some internal inconsistency (as the later exception implies).

BTW: 
1. Calling "context.complete()" in "AsyncListener.onError(AsyncEvent)" seems not to be a problem.
2. The exception also prevents a call to "AsyncListener.onError(AsyncEvent)", so a WriteListener can hide the end of the connection completely from the AsyncListener. However to my understand those should be to separate state machines...


Doing these tests, I recognized I did a lot of guessing about the interactions between the 3 different callbacks.
Is there any documentation on how they interact?


Regards,
  Steffen



> -----Ursprüngliche Nachricht-----
> Von: Steffen Heil (Mailinglisten) [mailto:lists@steffen-heil.de]
> Gesendet: Mittwoch, 26. August 2015 10:04
> An: Tomcat Users List <us...@tomcat.apache.org>
> Betreff: AW: Exception using Async Servlet
> 
> Hi
> 
> 
> > Make sure you are using the latest 8.0.26 release. There have been some fixes around async dispatch. If you still see the issue then
> > we'll need a test case (as simple as possible) that reproduces the issue for us to investigate.
> 
> I just upgraded to 8.0.26. But I see the same exception again:
> 
> Aug 26, 2015 9:42:41 AM org.apache.catalina.connector.CoyoteAdapter asyncDispatch
> SCHWERWIEGEND: Exception while processing an asynchronous request
> java.lang.IllegalStateException: Calling [asyncError()] is not valid for a request with Async state [MUST_COMPLETE]
> 	at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:351)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:820)
> 	at org.apache.coyote.Request.action(Request.java:378)
> 	at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:419)
> 	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:332)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1709)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:649)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1526)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1482)
> 	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:745)
> 
> 
> I *think* this happens in the following case:
> 
> 1. A client opens an html file using https that gets dispatched to an Async servlet.
> 
> 2. The servlet calls startAsync, registers read/write/context handlers:
> 	AsyncContext context = request.startAsync();
> 	context.setTimeout( 0 );
> 	ServletInputStream input = request.getInputStream();
> 	ServletOutputStream output = response.getOutputStream();
> 	ChannelProcessor processor = new ChannelProcessor( ... );
> 	context.addListener( processor );
> 	input.setReadListener( processor );
> 	output.setWriteListener( processor );
> 
> 3. The server writes some data to "output".
> 4. As the client is not sending data, "onAllDataRead" is called and the reference to "input" is dropped.
> 5. "onWritePossible" is called, but there is no more data to send for now.
> 6. The client window is closed. (BTW: The servlet is not notified about that at all.)
> 7. Later, an server event occurs and the server writes to "output" again (after checking "isReady").
> 
> I think this is the point, the exception is logged.
> 
> 
> I will try to create a testcase, but stripping down that code is far from easy as it is in the middle of a framework.
> 
> 
> I would also like to increase logging in tomcat, but I could not find out, how to do so.
> My current logging.properties consists of the following only:
> 
> 
> handlers = java.util.logging.ConsoleHandler
> .handlers = java.util.logging.ConsoleHandler
> 
> .level = TRACE
> org.apache.level = TRACE
> 
> 
> I suspect that should set any logger to TRACE, but only a few lines are logged...
> 
> 
> Regards,
>   Steffen


AW: Exception using Async Servlet

Posted by "Steffen Heil (Mailinglisten)" <li...@steffen-heil.de>.
Hi


> Make sure you are using the latest 8.0.26 release. There have been some fixes around async dispatch. If you still see the issue then
> we'll need a test case (as simple as possible) that reproduces the issue for us to investigate.

I just upgraded to 8.0.26. But I see the same exception again:

Aug 26, 2015 9:42:41 AM org.apache.catalina.connector.CoyoteAdapter asyncDispatch
SCHWERWIEGEND: Exception while processing an asynchronous request
java.lang.IllegalStateException: Calling [asyncError()] is not valid for a request with Async state [MUST_COMPLETE]
	at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:351)
	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:820)
	at org.apache.coyote.Request.action(Request.java:378)
	at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:419)
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:332)
	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1709)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:649)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1526)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1482)
	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:745)


I *think* this happens in the following case:

1. A client opens an html file using https that gets dispatched to an Async servlet.

2. The servlet calls startAsync, registers read/write/context handlers:
	AsyncContext context = request.startAsync();
	context.setTimeout( 0 );
	ServletInputStream input = request.getInputStream();
	ServletOutputStream output = response.getOutputStream();
	ChannelProcessor processor = new ChannelProcessor( ... );
	context.addListener( processor );
	input.setReadListener( processor );
	output.setWriteListener( processor );

3. The server writes some data to "output".
4. As the client is not sending data, "onAllDataRead" is called and the reference to "input" is dropped.
5. "onWritePossible" is called, but there is no more data to send for now.
6. The client window is closed. (BTW: The servlet is not notified about that at all.)
7. Later, an server event occurs and the server writes to "output" again (after checking "isReady").

I think this is the point, the exception is logged.


I will try to create a testcase, but stripping down that code is far from easy as it is in the middle of a framework.


I would also like to increase logging in tomcat, but I could not find out, how to do so.
My current logging.properties consists of the following only:


handlers = java.util.logging.ConsoleHandler
.handlers = java.util.logging.ConsoleHandler

.level = TRACE
org.apache.level = TRACE


I suspect that should set any logger to TRACE, but only a few lines are logged...


Regards,
  Steffen


Re: Exception using Async Servlet

Posted by Mark Thomas <ma...@apache.org>.
On 25/08/2015 17:05, Steffen Heil (Mailinglisten) wrote:
> Hi
> 
> 
> I am using servlets with startAsync to be able to read and write asynchronously.
> However from time to time the following is logged:
> 
> Aug 25, 2015 5:52:32 PM org.apache.catalina.connector.CoyoteAdapter asyncDispatch
> SCHWERWIEGEND: Exception while processing an asynchronous request
> java.lang.IllegalStateException: Calling [asyncError()] is not valid for a request with Async state [MUST_COMPLETE]
> 	at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:348)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:820)
> 	at org.apache.coyote.Request.action(Request.java:378)
> 	at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:406)
> 	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:332)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1709)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:649)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1527)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1484)
> 	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:745)
> 
> There is no code of our own involved so I am wondering if my configuration is invalid or I am using the servlet in an incorrect way.
> I would post some of the code we use here, but it is not really small, so where would I need to start searching or posting?

Make sure you are using the latest 8.0.26 release. There have been some
fixes around async dispatch. If you still see the issue then we'll need
a test case (as simple as possible) that reproduces the issue for us to
investigate.

Mark


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org