"IllegalStateException: Invalid for read" after upgrading to 12.0.16 from 12.0.15 #12729

ofrias · 2025-01-23T09:02:55Z

Jetty version(s)
Jetty 12.0.16

Jetty Environment
ee10

Java version/vendor (use: java -version)
openjdk version "21.0.5" 2024-10-15 LTS
OpenJDK Runtime Environment Temurin-21.0.5+11 (build 21.0.5+11-LTS)
OpenJDK 64-Bit Server VM Temurin-21.0.5+11 (build 21.0.5+11-LTS, mixed mode, sharing)

OS type/version
Ubuntu Linux 24.04.1

Description
We have a setup with 2 load balanced Jetty instances. After upgrading from Jetty 12.0.15 to Jetty 12.0.16 we have started seeing these exceptions when we restart the servers and sessions have to move between Jetty instances:

java.lang.IllegalStateException: Invalid for read: id=..... not resident
        at org.eclipse.jetty.session.ManagedSession.checkValidForRead(ManagedSession.java:479)
        at org.eclipse.jetty.session.ManagedSession.isNew(ManagedSession.java:778)
        at org.eclipse.jetty.ee10.servlet.ServletApiRequest.getSession(ServletApiRequest.java:522)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
...
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
        at org.eclipse.jetty.ee10.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1379)

How to reproduce?
It happens randomly when we restart Jetty instances, unfortunately we don't have a way to systematically reproduce it.

The text was updated successfully, but these errors were encountered:

gregw · 2025-01-24T06:38:13Z

Can you tell us what frames are in the ... of that stack trace? You can XXXX out any names you don't want us to see, but knowing the general type of frames would help.

ofrias · 2025-01-24T06:45:42Z

Oops, sorry. This is another example with all the Jetty and jakarta calls visible:

java.lang.IllegalStateException: Invalid for read: id=... not resident
        at org.eclipse.jetty.session.ManagedSession.checkValidForRead(ManagedSession.java:479)
        at org.eclipse.jetty.session.ManagedSession.isNew(ManagedSession.java:778)
        at org.eclipse.jetty.ee10.servlet.ServletApiRequest.getSession(ServletApiRequest.java:522)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
...
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
        at org.eclipse.jetty.ee10.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1379)
        at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:736)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1619)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1552)
        at org.eclipse.jetty.ee10.servlet.Dispatcher.forward(Dispatcher.java:126)
...
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
...
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
...
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:208)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
   ...
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1552)
        at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:819)
        at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:436)
        at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:469)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
        at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
        at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1060)
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:151)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:611)
        at org.eclipse.jetty.server.Server.handle(Server.java:182)
        at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:662)
        at org.eclipse.jetty.util.thread.Invocable$ReadyTask.run(Invocable.java:175)
        at org.eclipse.jetty.http2.server.internal.HttpStreamOverHTTP2$1.run(HttpStreamOverHTTP2.java:135)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:480)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:443)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produce(AdaptiveExecutionStrategy.java:195)
        at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:209)
        at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:156)
        at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:442)
        at [org.eclipse.jetty.io](http://org.eclipse.jetty.io/).FillInterest.fillable(FillInterest.java:99)
        at [org.eclipse.jetty.io](http://org.eclipse.jetty.io/).SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:480)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:443)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:201)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311)
        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)

gregw · 2025-01-24T08:03:17Z

Thanks for that. I can see three filters, the last of which does a dispatch to the Servlet.
We can also see that there is are two wrappers of the request applied. Can you tell us what request methods are overridden in those wrappers?

thanks

ofrias · 2025-01-24T08:21:45Z

I don't think we are explicitly configuring any request wrapper.

The call inmediately before
at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)

is:
request.getSession(true)

janbartel · 2025-01-24T11:00:13Z

@ofrias just to be clear, getSession(true) is not called prior to the forward dispatch, only after it?

Also, can you provide details of your configuration, such as:

are you using the DefaultSessionCache
what is the housekeeper sweep interval
what is the length of validity of a session
are session ids carried via cookies or url rewriting
any other settings you have configured on the SessionCache

ofrias · 2025-01-24T11:28:10Z

@ofrias just to be clear, getSession(true) is not called prior to the forward dispatch, only after it?

getSession(true) is called after the forward dispatch. At the end of this comment is the stack trace with the getSession(true) call position.

* are you using the `DefaultSessionCache`

I don't know, we are using --module=session-store-jdbc but I don't know if this uses DefaultSessionCache behing the scenes.

* what is the housekeeper sweep interval

We have not configured jetty.sessionScavengeInterval.seconds or jetty.session.gracePeriod.seconds so they should be the default.

* what is the length of validity of a session

This is our code in web.xml (by the way, __SAME_SITE_LAX__ is ignored)

    <session-config>
        <session-timeout>30</session-timeout>
        <cookie-config>
            <comment>__SAME_SITE_LAX__</comment>
            <http-only>true</http-only>
            <secure>true</secure>
        </cookie-config>
    </session-config>

* are session ids carried via cookies or url rewriting

cookies

* any other settings you have configured on the `SessionCache`

No

java.lang.IllegalStateException: Invalid for read: id=... not resident
        at org.eclipse.jetty.session.ManagedSession.checkValidForRead(ManagedSession.java:479)
        at org.eclipse.jetty.session.ManagedSession.isNew(ManagedSession.java:778)
        at org.eclipse.jetty.ee10.servlet.ServletApiRequest.getSession(ServletApiRequest.java:522)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
        at jakarta.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:221)
        
        request.getSession(true) call

	at XXX.doGet(XXX.java)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
        at org.eclipse.jetty.ee10.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1379)
        at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:736)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1619)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1552)
        at org.eclipse.jetty.ee10.servlet.Dispatcher.forward(Dispatcher.java:126)
        at XXX.doFilter(XXX.java)
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
        at XXX.doFilter(XXX.java)
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
        at XXX.doFilter(XXX.java)
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:208)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
        at XXX.doFilter(XXX.java)
        at jakarta.servlet.http.HttpFilter.doFilter(HttpFilter.java:97)
        at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1591)
        at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1552)
        at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:819)
        at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:436)
        at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:469)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
        at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
        at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1060)
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:151)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:611)
        at org.eclipse.jetty.server.Server.handle(Server.java:182)
        at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:662)
        at org.eclipse.jetty.util.thread.Invocable$ReadyTask.run(Invocable.java:175)
        at org.eclipse.jetty.http2.server.internal.HttpStreamOverHTTP2$1.run(HttpStreamOverHTTP2.java:135)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:480)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:443)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produce(AdaptiveExecutionStrategy.java:195)
        at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:209)
        at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:156)
        at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:442)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:99)
        at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:480)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:443)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293)
        at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:201)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311)
        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)

janbartel · 2025-01-24T15:43:46Z

Can you describe the scenario a little more? Is this a session that has previously been live on node 1, and is now being referenced for the first time on node 2? Or is this session likely to have been live on node 2 at some time in the past?

If practicable, enabling debug logging for sessions may give us some more information to go on, set logging for the package org.eclipse.jetty.session to level DEBUG, or the equivalent value for your logging system.

janbartel · 2025-01-29T09:24:35Z

@ofrias do you have any further info on this, such as the debug logs? Via code inspection I just can't see how you can have a reference to a non-resident session. The only time I've ever seen this is when application code keeps a reference to a session that was obtained from getSession() - which is something that must not be done.

ofrias · 2025-01-29T10:05:26Z

I rolled back to Jetty 12.0.15 two days ago and for the moment no occurrences of the issue, so this apparently confirms that it was introduced on version 12.0.16.

It happens when I restart the 2 load balancer servers (for example to update their code). First I stop number 1, code is updated, then I start number 1 again, then I stop number 2, code is updated, and finally I start number 2 again. Since they are load balanced, I assume that sessions move between them. When one is stopped its sessions are moved to the other one, and then they come back to it once it starts again. It seems to me that this exception is fired on these session "migrations".

We don't keep references to session instances.

I have not generated logs yet.

janbartel · 2025-01-29T11:45:35Z

The sessions are sticky, yes? What algorithm is being employed for the balancing?

ofrias · 2025-01-29T11:54:34Z

Yes, sessions are sticky in the sense that they are processed by the same server if it is available. But when a server is shutdown they are processed by the other one, and when it comes back they are dispatched again to the original server. So they are moved two times between servers on a restart.
The balancing is based on the source IP address.

ofrias · 2025-02-04T13:14:30Z

Please find attached a sample log (sorry for the delay). This happened while shutting down a server.
By the way, I can confirm that the issue was introduced on version 12.0.16 because I have been running 12.0.15 for a week and it never happened. With version 12.0.16 it happens almost on every restart.

jetty sample.log

janbartel · 2025-02-04T14:50:58Z

Thanks for that log, looks very useful. I'll have a closer look soon when I'm near a computer, but at first glance looks like an interaction between a newly created session that has not yet been persisted and the shutdown thread that tries to save all sessions before terminating. I don't recall any session code changing between 2.0.15 and 2.0.16, so it could just be the result of some timing differences due to code changes in other parts of jetty. BTW do you have saveOnCreate set to true for your session cache?

ofrias · 2025-02-04T15:17:41Z

BTW do you have saveOnCreate set to true for your session cache?

No, we have not configured saveOnCreate (or any other session-related setting except for jetty.sessionIdManager.workerName) so I think it is false (default).

janbartel · 2025-02-12T11:26:49Z

@ofrias I've got access to my computer again and checked the differences between 12.0.15 and 12.0.16 wrt the shutdown sequence, and I now know what is going on. We split out some of the handling of a graceful shutdown to a new module, called graceful, which I'm guessing you won't have enabled. The doco on it is here: https://jetty.org/docs/jetty/12/operations-guide/modules/standard.html#graceful

Prior to this change, we used to set the jetty.server.stop.timeOut in server module in the jetty-server.xml file, but this was removed in 12.0.16 and put into the new jetty-graceful.xml file instead. As you don't have the new graceful module enabled, your connectors aren't behaving nicely on shutdown and preventing acceptance of new connections. Nor will you have the GracefulHandler that ensures that the requests have all drained out before the DefaultSessionCache runs over the sessions and takes them out of the cache. So you are getting new requests coming in during shutdown, they're creating new sessions during shutdown and are in a race with the shutdown handling, leading to the errors you see.

Please enable the new graceful module, and let me know if this solves your issue.

In the meanwhile, I will look at modifying the code so that a read on a session that has been shutdown is permitted (albeit with a log message, probably debug log).

ofrias · 2025-02-12T12:11:03Z

OK, I have enabled the graceful module. I will let you know if this solves our issue. Thanks a lot for your help.

ofrias added the Bug For general bugs on Jetty side label Jan 23, 2025

gregw assigned janbartel Jan 24, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"IllegalStateException: Invalid for read" after upgrading to 12.0.16 from 12.0.15 #12729

"IllegalStateException: Invalid for read" after upgrading to 12.0.16 from 12.0.15 #12729

ofrias commented Jan 23, 2025

gregw commented Jan 24, 2025

ofrias commented Jan 24, 2025 •

edited

Loading

gregw commented Jan 24, 2025

ofrias commented Jan 24, 2025

janbartel commented Jan 24, 2025

ofrias commented Jan 24, 2025 •

edited

Loading

janbartel commented Jan 24, 2025

janbartel commented Jan 29, 2025

ofrias commented Jan 29, 2025

janbartel commented Jan 29, 2025

ofrias commented Jan 29, 2025 •

edited

Loading

ofrias commented Feb 4, 2025 •

edited

Loading

janbartel commented Feb 4, 2025

ofrias commented Feb 4, 2025 •

edited

Loading

janbartel commented Feb 12, 2025

ofrias commented Feb 12, 2025

"IllegalStateException: Invalid for read" after upgrading to 12.0.16 from 12.0.15 #12729

"IllegalStateException: Invalid for read" after upgrading to 12.0.16 from 12.0.15 #12729

Comments

ofrias commented Jan 23, 2025

gregw commented Jan 24, 2025

ofrias commented Jan 24, 2025 • edited Loading

gregw commented Jan 24, 2025

ofrias commented Jan 24, 2025

janbartel commented Jan 24, 2025

ofrias commented Jan 24, 2025 • edited Loading

janbartel commented Jan 24, 2025

janbartel commented Jan 29, 2025

ofrias commented Jan 29, 2025

janbartel commented Jan 29, 2025

ofrias commented Jan 29, 2025 • edited Loading

ofrias commented Feb 4, 2025 • edited Loading

janbartel commented Feb 4, 2025

ofrias commented Feb 4, 2025 • edited Loading

janbartel commented Feb 12, 2025

ofrias commented Feb 12, 2025

ofrias commented Jan 24, 2025 •

edited

Loading

ofrias commented Jan 24, 2025 •

edited

Loading

ofrias commented Jan 29, 2025 •

edited

Loading

ofrias commented Feb 4, 2025 •

edited

Loading

ofrias commented Feb 4, 2025 •

edited

Loading