You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Johannes Edmeier <jo...@gmail.com> on 2019/10/20 09:43:00 UTC

IOException: Broken Pipe causes "Calling [asyncError()] is not valid for a request with Async state [MUST_DISPATCH]" to be logged

Hi folks,

I have a async response which is designed to run as long as the
browser is connected (using SSE).
After the browser disconnects and data is written to the response
internally a "IOException: Broken Pipe" is thrown, which itself is not
logged, but there is some error from the state handling logged (see
below) which is quite noisy. Is there somehow to prevent this from
happening? or is this a bug?

(also happens with tomcat 9.0.27)
The spring boot guys also did have a lookt at it:
https://github.com/spring-projects/spring-boot/issues/15057

Cheerio
Johannes

```` 2018-11-02 11:43:33.016 ERROR 17152 --- [nio-8080-exec-2]
o.a.catalina.connector.CoyoteAdapter     : Exception while processing
an asynchronous request

java.lang.IllegalStateException: Calling [asyncError()] is not valid
for a request with Async state [MUST_DISPATCH]
at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:440)
~[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:494)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.coyote.Request.action(Request.java:430)
~[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:382)
~[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239)
~[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:241)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:770)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1415)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[na:1.8.0_181]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[na:1.8.0_181]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
[tomcat-embed-core-9.0.12.jar:9.0.12]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
```

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


Re: IOException: Broken Pipe causes "Calling [asyncError()] is not valid for a request with Async state [MUST_DISPATCH]" to be logged

Posted by Mark Thomas <ma...@apache.org>.
On 20/10/2019 21:15, Johannes Edmeier wrote:
> Am So., 20. Okt. 2019 um 16:11 Uhr schrieb Mark Thomas <ma...@apache.org>:
>>
>> On October 20, 2019 9:43:00 AM UTC, Johannes Edmeier <jo...@gmail.com> wrote:
>>> Hi folks,
>>>
>>> I have a async response which is designed to run as long as the
>>> browser is connected (using SSE).
>>> After the browser disconnects and data is written to the response
>>> internally a "IOException: Broken Pipe" is thrown, which itself is not
>>> logged, but there is some error from the state handling logged (see
>>> below) which is quite noisy. Is there somehow to prevent this from
>>> happening? or is this a bug?
>>
>> It may be an application bug or a Tomcat bug. The Tomcat side of things has been cleaned up for 9.9.28.
>>
>> Mark
>>
> 
> Thanks for your quick response. I did test it with the 9.0.28-dev and
> indeed the error isn't logged anymore.
> Thanks a lot and keep up the good work!

Thanks for the feedback.

It is worth pointing out (as this thread seems as relevant as any) that
as soon as you see an I/O error on an async thread the expectation is that:

- the async thread exists immediately (well, doesn't attempt to read
from the request, write to the response, call complete() etc.)
- Tomcat will call the onError() method of any attached AsyncListeners
- One of those listeners will call complete() or dispatch()
- If there is no call to complete() or dispatch(), Tomcat will call
complete()

It is that first step that usually where things start to go wrong.

Mark

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


Re: IOException: Broken Pipe causes "Calling [asyncError()] is not valid for a request with Async state [MUST_DISPATCH]" to be logged

Posted by Johannes Edmeier <jo...@gmail.com>.
Am So., 20. Okt. 2019 um 16:11 Uhr schrieb Mark Thomas <ma...@apache.org>:
>
> On October 20, 2019 9:43:00 AM UTC, Johannes Edmeier <jo...@gmail.com> wrote:
> >Hi folks,
> >
> >I have a async response which is designed to run as long as the
> >browser is connected (using SSE).
> >After the browser disconnects and data is written to the response
> >internally a "IOException: Broken Pipe" is thrown, which itself is not
> >logged, but there is some error from the state handling logged (see
> >below) which is quite noisy. Is there somehow to prevent this from
> >happening? or is this a bug?
>
> It may be an application bug or a Tomcat bug. The Tomcat side of things has been cleaned up for 9.9.28.
>
> Mark
>

Thanks for your quick response. I did test it with the 9.0.28-dev and
indeed the error isn't logged anymore.
Thanks a lot and keep up the good work!

Johannes

>
> >
> >(also happens with tomcat 9.0.27)
> >The spring boot guys also did have a lookt at it:
> >https://github.com/spring-projects/spring-boot/issues/15057
> >
> >Cheerio
> >Johannes
> >
> >```` 2018-11-02 11:43:33.016 ERROR 17152 --- [nio-8080-exec-2]
> >o.a.catalina.connector.CoyoteAdapter     : Exception while processing
> >an asynchronous request
> >
> >java.lang.IllegalStateException: Calling [asyncError()] is not valid
> >for a request with Async state [MUST_DISPATCH]
> >at
> >org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:440)
> >~[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:494)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at org.apache.coyote.Request.action(Request.java:430)
> >~[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:382)
> >~[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239)
> >~[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:241)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:770)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1415)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at
> >java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> >[na:1.8.0_181]
> >at
> >java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> >[na:1.8.0_181]
> >at
> >org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> >[tomcat-embed-core-9.0.12.jar:9.0.12]
> >at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
> >```
> >
> >---------------------------------------------------------------------
> >To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> >For additional commands, e-mail: users-help@tomcat.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>

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


Re: IOException: Broken Pipe causes "Calling [asyncError()] is not valid for a request with Async state [MUST_DISPATCH]" to be logged

Posted by Mark Thomas <ma...@apache.org>.
On October 20, 2019 9:43:00 AM UTC, Johannes Edmeier <jo...@gmail.com> wrote:
>Hi folks,
>
>I have a async response which is designed to run as long as the
>browser is connected (using SSE).
>After the browser disconnects and data is written to the response
>internally a "IOException: Broken Pipe" is thrown, which itself is not
>logged, but there is some error from the state handling logged (see
>below) which is quite noisy. Is there somehow to prevent this from
>happening? or is this a bug?

It may be an application bug or a Tomcat bug. The Tomcat side of things has been cleaned up for 9.9.28.

Mark


>
>(also happens with tomcat 9.0.27)
>The spring boot guys also did have a lookt at it:
>https://github.com/spring-projects/spring-boot/issues/15057
>
>Cheerio
>Johannes
>
>```` 2018-11-02 11:43:33.016 ERROR 17152 --- [nio-8080-exec-2]
>o.a.catalina.connector.CoyoteAdapter     : Exception while processing
>an asynchronous request
>
>java.lang.IllegalStateException: Calling [asyncError()] is not valid
>for a request with Async state [MUST_DISPATCH]
>at
>org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:440)
>~[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:494)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at org.apache.coyote.Request.action(Request.java:430)
>~[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:382)
>~[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239)
>~[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:241)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:770)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1415)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at
>java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>[na:1.8.0_181]
>at
>java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>[na:1.8.0_181]
>at
>org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>[tomcat-embed-core-9.0.12.jar:9.0.12]
>at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
>```
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>For additional commands, e-mail: users-help@tomcat.apache.org


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