userA tries to use on its browser the application's url userA appears to have logon as userB as the session cookie actually belongs to userB. In such cases tomcat restart is needed and users need to logout and login again and it seems that the problem is resolved by this workaround. The application uses the embedded tomcat v8.5.64, we already have the following property set to true. org.apache.catalina.connector.RECYCLE_FACADES=true We are observing in catalina logs multiple incidents of "The request object has been recycled and is no longer associated with this facade" The full stack trace below: 2021-11-26 18:33:35,526 ERROR [[default]] - Servlet.service() for servlet [default] threw exception2021-11-26 18:33:35,526 ERROR [[default]] - Servlet.service() for servlet [default] threw exceptionjava.lang.IllegalStateException: The request object has been recycled and is no longer associated with this facade at org.apache.catalina.connector.RequestFacade.getHeader(RequestFacade.java:686) at javax.servlet.http.HttpServletRequestWrapper.getHeader(HttpServletRequestWrapper.java:87) at org.apache.catalina.servlets.DefaultServlet.checkIfMatch(DefaultServlet.java:2315) at org.apache.catalina.servlets.DefaultServlet.checkIfHeaders(DefaultServlet.java:788) at org.apache.catalina.servlets.DefaultServlet.serveResource(DefaultServlet.java:903) at org.apache.catalina.servlets.DefaultServlet.doGet(DefaultServlet.java:510) at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) at org.apache.catalina.servlets.DefaultServlet.service(DefaultServlet.java:490) at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:711) at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:460) at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:387) at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:315) at org.tuckey.web.filters.urlrewrite.NormalRewrittenUrl.doRewrite(NormalRewrittenUrl.java:213) at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:171) at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at net.openscape.webclient.servlet.ResponseHeaderFilter.doFilter(ResponseHeaderFilter.java:65) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:544) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:698) at com.siemens.ca.http.server.catalina.DumperValve.invoke(DumperValve.java:321) at com.siemens.ca.http.server.catalina.CharacterEncodingValve.invoke(CharacterEncodingValve.java:42) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:364) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:616) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:831) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1629) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:820)2021-11-26 18:33:35,527 ERROR [[default]] - Servlet.service() for servlet [default] in context with path [/openscapeuc] threw exceptionjava.lang.NullPointerException at org.apache.catalina.connector.RequestFacade.isAsyncStarted(RequestFacade.java:1044) at javax.servlet.ServletRequestWrapper.isAsyncStarted(ServletRequestWrapper.java:414) at org.apache.catalina.core.ApplicationDispatcher.unwrapRequest(ApplicationDispatcher.java:790) at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:766) at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:460) at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:387) at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:315) at org.tuckey.web.filters.urlrewrite.NormalRewrittenUrl.doRewrite(NormalRewrittenUrl.java:213) at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:171) at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at net.openscape.webclient.servlet.ResponseHeaderFilter.doFilter(ResponseHeaderFilter.java:65) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:544) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:698) at com.siemens.ca.http.server.catalina.DumperValve.invoke(DumperValve.java:321) at com.siemens.ca.http.server.catalina.CharacterEncodingValve.invoke(CharacterEncodingValve.java:42) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:364) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:616) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:831) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1629) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:820) Apart from the above multiple exceptions are also reported: 2021-11-26 18:30:42,412 INFO [CoyoteAdapter] - Encountered a non-recycled request and recycled it forcedly. org.apache.catalina.connector.CoyoteAdapter$RecycleRequiredException at org.apache.catalina.connector.CoyoteAdapter.checkRecycled(CoyoteAdapter.java:546) at org.apache.coyote.http11.Http11Processor.recycle(Http11Processor.java:1577) at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1021) at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1054) at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.close(NioEndpoint.java:1260) at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doClose(WsRemoteEndpointImplServer.java:173) at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.close(WsRemoteEndpointImplBase.java:739) at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWritePossible(WsRemoteEndpointImplServer.java:148) at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doWrite(WsRemoteEndpointImplServer.java:77) at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:509) at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsRemoteEndpointImplBase.java:395) at org.apache.tomcat.websocket.WsRemoteEndpointImplBase$TextMessageSendHandler.write(WsRemoteEndpointImplBase.java:832) at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendStringByCompletion(WsRemoteEndpointImplBase.java:213) at org.apache.tomcat.websocket.WsRemoteEndpointAsync.sendText(WsRemoteEndpointAsync.java:47) at org.atmosphere.container.version.JSR356WebSocket.write(JSR356WebSocket.java:73) at org.atmosphere.websocket.WebSocket.write(WebSocket.java:255) at org.atmosphere.websocket.WebSocket.write(WebSocket.java:220) at org.atmosphere.websocket.WebSocket.write(WebSocket.java:46) at org.atmosphere.cpr.AtmosphereResponseImpl$Stream.write(AtmosphereResponseImpl.java:956) at org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl.java:802) at org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl.java:783) at org.atmosphere.cpr.AtmosphereResourceImpl.write(AtmosphereResourceImpl.java:587) at net.openscape.webclient.websocket.DirectClient$ResourceWriter.run(DirectClient.java:117) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.lang.Thread.run(Thread.java:820) and also 2021-12-02 10:58:20,281 ERROR [org.apache.coyote.http11.Http11Processor] Error processing request2021-12-02 10:58:20,281 ERROR [org.apache.coyote.http11.Http11Processor] Error processing requestjava.lang.AssertionError at org.apache.catalina.mapper.Mapper.internalMap(Mapper.java:744) at org.apache.catalina.mapper.Mapper.map(Mapper.java:702) at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:714) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:358) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:616) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:831) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1629) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:820)
Usually this kind of thing is caused by an application retaining references to object references like the session, request, or response. Can you please confirm that you are not keeping any references to any of these types of objects? Are you using any long-running processes that are outside of the "normal" servlet access pattern like request -> servlet -> response? For example, are you using Websocket or "servlet async" features? Are you able to upgrade to the latest Tomcat (8.5.73) just in case something has been fixed?
Hi, We have already checked if there are any possible "leaked" references to the request/response/session objects outside of their normal scope, but this doesn't seem to be the case. Just to give you a better understanding of our situation, we have a Servlet Filter which performs an automatic login based on a Cookie (by default this Cookie expires after 30 days). After each automatic login this expiration date is refreshed again in order to make it last for 30 days more. You can see a simple representation of this implementation in the following snippet using pseudocode for a better understanding: ************************************************************** public class AuthenticationCheckFilter implements Filter { ... public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException { ... // If (user is not logged) // Read authentication cookie from "request" object. // Perform automatic login using the cookie. // Refresh the cookies expiration date in order to be valid for // 30 days more using the "response" object. // End If ... } ... } *************************************************************** So if the user is not logged in (does not have a valid session at that point) the authentication cookie (from the "request" object) is read and used in order to perform an automatic login. After the successful completion of the automatic login, the cookie's expiration date is refreshed (by using the "response" object). The problem is that the response with the updated cookie ends up to a different user session from the one that it was supposed to go. So a different user will receive the SET-COOKIE header (with the updated expiration date) that was intended for another user and he will be able to eventually login to the other user's account. In our understanding there is not something wrong with our logic here that might end up mixing different user sessions since we don't keep any reference on the request/response objects outside of the doFilter method. We just use the request/response objects that are provided as parameters from the doFilter method which are related to the current user session and not any other external references on other sessions. We are not sure if the previously mentioned errors are related to the mixing of the different user sessions (or this could be a "silent" bug without traces) but these are the only ones that are reported in the catalina logs. Regarding you second question yes we are using Websockets and more specifically we are using the atmosphere websocket framework (as it can be seen from the second stack trace which seems to be related to WebSockets). We have already upgraded our software to use the latest Tomcat version (8.5.73) and so far the issue has not been reproduced yet (but keep in mind that this is not easily reproduced). However since this is a really critical issue we couldn't risk it by just waiting if the new version will fix this issue and that's why we opened this ticket (we also couldn't find anything related in the old reported/resolved issues). In the past we were using version 8.0.49 (until it 8.0.X reached EOL) and we later moved to version 8.5.43 but we never had such issues until the point we upgraded to version 8.5.64. Also note that during these upgrades we didn't perform any change to other stongly related (to this flow) libraries/frameworks that could be "suspected" as problematic (websocket atmosphere framework, Jersey) that's why we think that this is a Tomcat issue.
Thanks for the background. Sometimes that provides enough information for us to be able to identify a possible root cause. Unfortunately, that doesn't seem to be the case in this instance. I have also reviewed the change log from 8.5.43 to 8.5.64 and don't see any likely candidates. Can you confirm you are not using HTTP/2? This type of issue is always very sensitive to timing. It could be that you are seeing a bug introduced between 8.5.43 and 8.5.64 that was then fixed between 8.5.64 and 8.5.73. What I suspect is more likely is that the bug has been present all the way through and that the changes in Tomcat changed the timing which in turn changed how likely it was that you saw the bug. Since you are on Linux, it would be worth testing to see if your system is susceptible to this bug: https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1924298 There is a C test application attached to the linked Java bug along with instructions (using wrk) on how to reproduce the issue. If you do see duplicated accepts that might be an explanation for this issue. What we really need is a reproducible test case. Once we have that I am confident we'll be able to find the root cause and fix it (if it is in Tomcat). The more reliably the test case reproduces the issue, the quicker we'll be able to fix it. Generally, it is less about how many requests it takes to trigger the issue and more about how quickly the test triggers the issue.
Thank you for your prompt response. We are not using HTTP/2. We just tried to reproduce the bug you mentioned and we were able to see this faulty behavior in SUSE Linux Enterprise Server 12 SP5 as well. From the description of this bug it seems this creates duplicate file descriptors that refer to the same connection. Is it sure that these duplicate file descriptors might be causing users to receive response intended for other users? It's really difficult for us to prepare some kind of test case because this issue is not easily reproduced and we are not sure what triggers it.
(In reply to dimitrios.psymarnos from comment #4) > We are not using HTTP/2. ACK. > We just tried to reproduce the bug you mentioned and we were able to see > this faulty behavior in SUSE Linux Enterprise Server 12 SP5 as well. If you can open a bug / support issue for SUSE that would be helpful. A link to the bug report would also be helpful. > From the description of this bug it seems this creates duplicate file > descriptors that refer to the same connection. Is it sure that these > duplicate file descriptors might be causing users to receive response > intended for other users? I don't know. I can't immediately think of a failure scenario where that could happen but duplicate references to the same connection is going to trigger some strange errors. It isn't a scenario that was in anyone's mind when the Tomcat code was written. Depending on how those errors are handled, it might be able to trigger the problem you are seeing. So I guess my position is that I wouldn't rule it out but neither would I class it as a likely cause. > It's really difficult for us to prepare some kind of test case because this > issue is not easily reproduced and we are not sure what triggers it. Understood. It is even more difficult for us to fix it. Please do add more information as and when you have some but, for now, this issue is going to remain in the NEEDINFO state until we have a test case we can use to reproduce it.
Marking this as a duplicate of the the earlier bug since the root cause is the same. *** This bug has been marked as a duplicate of bug 65408 ***