How to handle "Warning Logs in org.eclipse.jetty.ee8.nested.HttpChannelState and org.eclipse.jetty.server.internal.HttpChannelState"? (original) (raw)

Jetty Version
12.0.22

Jetty Environment
ee8, ee10

Java Version
Temurin-17.0.16+8 (build 17.0.16+8)

Question
Frequently seeing a lot (17k times) of the following warning logs in our application:

• ... WARNING ... [org.eclipse.jetty.ee8.nested, HttpChannelState] java.io.IOException: Pending read in onCompleted
  -> originating from Jetty method HttpConnection#succeeded
• ... WARNING [<server,14>] [org.eclipse.jetty.ee8.nested, HttpChannelState] java.util.concurrent.TimeoutException: Idle timeout expired: 120000/120000 ms
  -> originating from Jetty method IdleTimeout#checkIdleTimeout

Analysis
After looking into the Jetty source code one can see that:

• Jetty method HttpChannelState#startAsync registers a listener for asynchronous fatal failures -> called once the effects of the failure have already taken place
• Jetty method HttpChannelState#asyncError writes the above mentioned warning log(s)

I would appreciate to know more about the what exactly leads to this and what should/could one do especially for java.io.IOException: Pending read in onCompleted?
Missing details about the original async request being processed, etc. and therefore no chance to find out the culprit most-likely a client behaving awkward.

--

Less frequently the following warning log in our application:

• WARNING ... [org.eclipse.jetty.server, Response] writeError: status=500, message=java.lang.IllegalStateException: demand pending, response=ErrorResponse@590eb90a{500,POST@1a8ac353 http://<<host>>/<<path>>?<<query-params>> HTTP/1.1} java.lang.IllegalStateException: demand pending at org.eclipse.jetty.server.internal.HttpChannelState$ChannelCallback.succeeded(HttpChannelState.java:1544) at org.eclipse.jetty.util.Callback$Nested.succeeded(Callback.java:435) at org.eclipse.jetty.util.CountingCallback.succeeded(CountingCallback.java:63) at org.eclipse.jetty.ee8.nested.HttpChannel.onCompleted(HttpChannel.java:762) at org.eclipse.jetty.ee8.nested.HttpChannel.handle(HttpChannel.java:450) at org.eclipse.jetty.ee8.nested.HttpChannel.run(HttpChannel.java:430) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166) at java.base/java.lang.Thread.run(Thread.java:840) Suppressed: java.io.IOException: content-length 74 != 0 written at org.eclipse.jetty.server.internal.HttpChannelState$ChannelCallback.succeeded(HttpChannelState.java:1564) ... 9 more Suppressed: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:167) at org.eclipse.jetty.io.IdleTimeout.idleCheck(IdleTimeout.java:113) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ... 1 more
  -> originating from Jetty method HttpChannelState#succeeded

--

Thanks in advance.