Seeing java.lang.IllegalArgumentException: demand pending during load testing

[joakime]

Jetty version(s)
12.0.8

Jetty Environment
ee10

Java version/vendor (use: java -version)
JDK21

OS type/version
Linux

Description

java.lang.IllegalArgumentException: demand pending
 	at org.eclipse.jetty.server.internal.HttpChannelState$ChannelRequest.demand(HttpChannelState.java:955)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.handler.ContextRequest.demand(ContextRequest.java:41)
 	at org.eclipse.jetty.ee10.servlet.AsyncContentProducer.isReady(AsyncContentProducer.java:252)
 	at org.eclipse.jetty.ee10.servlet.HttpInput.run(HttpInput.java:325)
 	at org.eclipse.jetty.ee10.servlet.ServletChannel.lambda$handle$1(ServletChannel.java:537)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1292)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1285)
 	at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:537)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1298)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.lambda$execute$0(ContextHandler.java:1315)
 	at org.eclipse.jetty.util.thread.MonitoredQueuedThreadPool$1.run(MonitoredQueuedThreadPool.java:73)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164)
 	at java.base/java.lang.Thread.run(Thread.java:1583)

How to reproduce?

Load testing

[lorban]

Here is my theory about what could be the cause of this:

TL;DR I think Jersey is reading from the ServletInputStream while the core Handler's callback is being succceeded.

IAE thrown because HttpChannelState._onContentAvailable != null:

  if (httpChannelState._onContentAvailable != null)
    throw new IllegalArgumentException("demand pending");

The recycling happens when the core Handler's callback is succeeded and its order is:

HttpStreamOverHttp1.succeeded()
  CompletionStreamWrapper.succeeded()
    CompletionStreamWrapper.onCompletion()
      ServletChannel.recycle()
        ServletChannelState.recycle() // resets the inputState to IDLE
        << if the thread with the stack below executes here, it throws ISE >>
        HttpInput.recycle() // flips the ContentProducer to the blocking one, making isReady() return false 
  HttpChannelState.recycle()
    _onContentAvailable = null

Repeating the reported stack trace:

java.lang.IllegalArgumentException: demand pending
 	at org.eclipse.jetty.server.internal.HttpChannelState$ChannelRequest.demand(HttpChannelState.java:955)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.Request$Wrapper.demand(Request.java:803)
 	at org.eclipse.jetty.server.handler.ContextRequest.demand(ContextRequest.java:41)
 	at org.eclipse.jetty.ee10.servlet.AsyncContentProducer.isReady(AsyncContentProducer.java:252)
 	at org.eclipse.jetty.ee10.servlet.HttpInput.run(HttpInput.java:325)
 	at org.eclipse.jetty.ee10.servlet.ServletChannel.lambda$handle$1(ServletChannel.java:537)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1292)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1285)
 	at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:537)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1298)
 	at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.lambda$execute$0(ContextHandler.java:1315)
 	at org.eclipse.jetty.util.thread.MonitoredQueuedThreadPool$1.run(MonitoredQueuedThreadPool.java:73)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209)
 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164)
 	at java.base/java.lang.Thread.run(Thread.java:1583)

If ServletInputStream.read() executes DURING the handler's callback being succeeded:

HttpInput.read()
  AsyncContentProducer.nextChunk() // returns EOF
  _consumedEof = true;
  // If EOF do we need to wake for allDataRead callback?
  if (onContentProducible()) // sets inputState to READY; also sets state to WOKEN if it was WAITING, return true in that case
    scheduleReadListenerNotification(); // dispatches a thread that will have the stack trace above

The dispatched thread would eventually call AsyncContentProducer.isReady() which could see that the inputState is IDLE if it happens between ServletChannelState.recycle() and HttpInput.recycle(). In that case, it would try to register a demand.

Can we have a demand already registered at this point?
YES! because the thread that called HttpInput.read() would have this loop:

while (isReady()) // sets the inputState to READY and returns true on the 1st check; sets the inputState to UNREADY, registers a demand and returns false on the 2nd check
 httpInput.read(); // reads -1, prepares the dispatch to call onAllDataRead()

But that needs to be confirmed.