https://bz.apache.org/bugzilla/show_bug.cgi?id=63791
Bug ID: 63791
Summary: Incomplete response + Exceptions thrown when using NIO
adapter
Product: Tomcat 9
Version: 9.0.26
Hardware: Macintosh
Status: NEW
Severity: normal
Priority: P2
Component: Util
Assignee: dev@tomcat.apache.org
Reporter: erikbeerep...@hush.com
Target Milestone: -----
Created attachment 36805
--> https://bz.apache.org/bugzilla/attachment.cgi?id=36805&action=edit
Minimal sample app demonstrating the issue
Apologies for the somewhat vague title. I'm filing this as a Tomcat bug as
tomcat appears to be throwing exceptions, any the tracing I've done points to
an issue with the Nio and/or Nio2 implementation. If I'm wrong, please let me
know and I'll go over to Spring.
Here's my situation:
- Using tomcat in a Spring Webflux app
- Enabled Spring Actuator + Prometheus registry for metrics
This was generated here: https://start.spring.io/ using the following
parameters:
- Gradle project
- Kotlin as the language
- Spring Boot 2.1.8
- Add webflux + actuator as deps
Start the app, and start making requests to get the default spring metrics from
prometheus:
curl -X GET http://localhost:8080/actuator/prometheus
After a few requests, the client will display an error, typically:
"Premature end of Content-Length delimited message body (expected: 8,705;
received: 8,061)"
In the logs, I see:
2019-09-30 15:34:08.867 ERROR 91885 --- [nio-8080-exec-4]
o.a.coyote.http11.Http11NioProtocol : Error reading request, ignored
java.lang.IllegalStateException: Calling [asyncOperation()] is not valid for a
request with Async state [COMPLETING]
at
org.apache.coyote.AsyncStateMachine.asyncOperation(AsyncStateMachine.java:269)
~[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:203)
~[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53)
~[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860)
~[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
[tomcat-embed-core-9.0.24.jar:9.0.24]
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.24.jar:9.0.24]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
2019-09-30 15:34:08.868 INFO 91885 --- [nio-8080-exec-4]
o.a.catalina.connector.CoyoteAdapter : Encountered a non-recycled request
and recycled it forcedly.
org.apache.catalina.connector.CoyoteAdapter$RecycleRequiredException: null
at
org.apache.catalina.connector.CoyoteAdapter.checkRecycled(CoyoteAdapter.java:525)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.http11.Http11Processor.recycle(Http11Processor.java:1329)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1055)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:1023)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
[tomcat-embed-core-9.0.24.jar:9.0.24]
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
[tomcat-embed-core-9.0.24.jar:9.0.24]
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.24.jar:9.0.24]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
It appears the magic size is 8192 (as indicated in the message). If I turn off
metrics such that the payload is below this size, none of these errors occur.
It appears this coincides with some configurable tomcat socket params such as
"socket.appReadBufSize" though tweaking those values had no effect.
I've attached a minimal sample app. Let me know if there's any further
information to provide.
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
