Error when storing a session

[severinfl]

Environment

Appengine Standard Java 21 (EE10)

Problem

On Saving a Session after processing a request we get an error:

Unable to release Session AppEngineSession@4eb65c63{id=C0oSpqulxPbxIESCPxbQkw,x=C0oSpqulxPbxIESCPxbQkw.node0,req=0,res=true}
java.lang.NullPointerException: Operation not allowed in a thread that is neither the original request thread nor a thread created by ThreadManager
at com.google.appengine.api.NamespaceManager.set(NamespaceManager.java:112)
at com.google.apphosting.runtime.jetty.DatastoreSessionStore$SessionDataStoreImpl.entityFromSession(DatastoreSessionStore.java:232)
at com.google.apphosting.runtime.jetty.DatastoreSessionStore$SessionDataStoreImpl.doStore(DatastoreSessionStore.java:148)
at org.eclipse.jetty.session.AbstractSessionDataStore.lambda$store$2(AbstractSessionDataStore.java:196)
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.session.SessionContext.run(SessionContext.java:92)
at org.eclipse.jetty.session.AbstractSessionDataStore.store(AbstractSessionDataStore.java:207)
at org.eclipse.jetty.session.CachingSessionDataStore.store(CachingSessionDataStore.java:131)
at org.eclipse.jetty.session.AbstractSessionCache.release(AbstractSessionCache.java:515)
at org.eclipse.jetty.session.AbstractSessionManager.complete(AbstractSessionManager.java:229)
at org.eclipse.jetty.session.AbstractSessionManager$SessionStreamWrapper.doComplete(AbstractSessionManager.java:1478)
at org.eclipse.jetty.server.handler.ContextHandler$ScopedContext.run(ContextHandler.java:1298)
at org.eclipse.jetty.session.AbstractSessionManager$SessionStreamWrapper.succeeded(AbstractSessionManager.java:1467)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.completeStream(HttpChannelState.java:728)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:654)
at com.google.apphosting.runtime.jetty.delegate.internal.DelegateConnection.lambda$handle$0(DelegateConnection.java:145)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter$2.run(JettyServletEngineAdapter.java:136)
at com.google.apphosting.runtime.jetty.delegate.internal.DelegateConnection.handle(DelegateConnection.java:141)
at com.google.apphosting.runtime.jetty.delegate.DelegateConnector.service(DelegateConnector.java:49)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:267)
at com.google.apphosting.runtime.RequestRunner.dispatchServletRequest(RequestRunner.java:262)
at com.google.apphosting.runtime.RequestRunner.dispatchRequest(RequestRunner.java:227)
at com.google.apphosting.runtime.RequestRunner.run(RequestRunner.java:193)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:273)
at java.base/java.lang.Thread.run(Thread.java:1583)

It seems to be that the ApiProxy.getCurrentEnvironment() is returning null on the NamespaceManager.set call.
here someone had a similar problem. We did not had any problems after migrating from java8 to java21 in march. The error occurs since sunday (05.05.2024). In contrast to the problem mentioned in Stackoverflow, we do not access the ApiProxy directly from our code, it is the call from the appengine library. Was there a change on the underlying structure?

Please let me know if you need some additional information.

[ludoch]

Looking...
Is it a fatal error?
Anyway we can get a snippet of session usage that would repro the case?
If you want a quick personal rollback, you could try these instructions (i.e bundle a previous set of runtime jars in your app, change the boot entrypoint and redeploy to use the working jars for your) : https://github.com/GoogleCloudPlatform/appengine-java-standard/blob/main/TRYLATESTBITSINPROD.md

Try release version 2.0.26

Let us know how it goes.

[ludoch]

Some progress: I can repro the issue on a modified app I have.
This is a critical step to investigate.
Also, the issue is not fatal, the JVM is not stopping.

Also confirmed it is only for java21 with jetty12. other runtimes with jetty9 are not affected.

[severinfl]

Thanks for your quick reply.

Good, that you can reproduce the error. Right now I'm working on the rollback like you mentioned.
Yes the issue is not fatal, but in our case it leads to login and authentication problems 😕.

[ludoch]

Initiating a java21 runtime global rollback now. ETA ~< 3h

[ludoch]

Investigating more this change. https://github.com/GoogleCloudPlatform/appengine-java-standard/pull/102/files

[ludoch]

Pushed a modified test in branch sessionbug that can repro the issue:
https://github.com/GoogleCloudPlatform/appengine-java-standard/tree/sessionbug

[ludoch]

Converging on https://github.com/GoogleCloudPlatform/appengine-java-standard/pull/96/files#diff-e47858fa5636dceca868cffdc03669712edf1e3f793dd70b6d842cfbceb9274a

[ludoch]

Reverting the 2 files in EE8AppVersionHandlerFactory and EE10AppVersionHandlerFactory from this PR makes the new test pass.

Tried to save the ApiProxy.Environment current = ApiProxy.getCurrentEnvironment();
seen in enterscope() and restore it in exitScope() but did not help.

[ludoch]

Fix is in. We will restart prod push tomorrow after nightly e2e system tests and probers in QA env.

[ludoch]

f1842ec