Thank you, Christopher. Your feedback was very helpful. -----Original Message----- From: Christopher Schultz <ch...@christopherschultz.net> Sent: Monday, May 17, 2021 5:33 PM To: users@tomcat.apache.org Subject: Re: ExpiresFilter throws NPE repeatedly
Todd, On 5/17/21 15:37, Todd Patch wrote: > Hello, > > I am working on troubleshooting an issue where I am seeing the following > Stack trace in a set of logs. Once this first message occurs, thousands of > the same message are logged for several hours. I am trying to track down the > origin of the issue. The issue is in the ExpiresFilter where the > servletOutputStream in the XServletOutputStream inner class is null. I am > not sure if that is the root cause of the issue or something else that has > happened to cause this. I have spent several hours trying to reproduce the > issue, but unsuccessful. However, it has been seen several times. I am > thinking it is actually related to a resource expiring because it usually > manifests on a Monday morning after a weekend of being idle. The > expiresFilter settings in Tomcat are the default settings. > > Tomcat Server Version information > Server version name: Apache Tomcat/8.5.54 > Server built: Apr 3 2020 14:06:10 UTC > Server version number: 8.5.54.0 > OS Name: Linux > OS Version: 4.14.173-137.228.amzn2.x86_64 > Architecture: amd64 > JVM Version: 1.8.0_202-b08 > > > [2021/04/26 10:58:15.486][ > INFO][com.loftware.comet.modelstatus.ModelStatusConsumer](ActiveMQ > Session Task-50127) Exception handling the message: > java.lang.RuntimeException: java.lang.RuntimeException: > java.lang.NullPointerException > java.lang.RuntimeException: java.lang.RuntimeException: > java.lang.NullPointerException > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:812) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:784) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResourceImpl.write(AtmosphereResourceImpl > .java:592) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > com.loftware.comet.modelstatus.ModelStatusConsumer.onMessage(ModelStat > usConsumer.java:145) [classes/:2019.3.4-9-1] > at > org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageCo > nsumer.java:1404) [activemq-client-5.15.10.jar:5.15.10] > at > org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionEx > ecutor.java:131) [activemq-client-5.15.10.jar:5.15.10] > at > org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExe > cutor.java:202) [activemq-client-5.15.10.jar:5.15.10] > at > org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.j > ava:133) [activemq-client-5.15.10.jar:5.15.10] > at > org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.jav > a:48) [activemq-client-5.15.10.jar:5.15.10] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j > ava:1149) [?:1.8.0_202] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. > java:624) [?:1.8.0_202] > at java.lang.Thread.run(Thread.java:748) [?:1.8.0_202] > Caused by: java.lang.RuntimeException: java.lang.NullPointerException > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:812) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:784) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.writeReady(AtmosphereIn > terceptorWriter.java:92) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.invokeInterceptor(Atmos > phereInterceptorWriter.java:83) > ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterce > ptorWriter.java:69) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterce > ptorWriter.java:64) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl$Stream.write(AtmosphereRespo > nseImpl.java:957) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:803) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > ... 11 more > Caused by: java.lang.NullPointerException > at > org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.doWrite > (Http11OutputBuffer.java:623) ~[tomcat-coyote.jar:8.5.54] > at > org.apache.coyote.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOu > tputFilter.java:119) ~[tomcat-coyote.jar:8.5.54] > at > org.apache.coyote.http11.Http11OutputBuffer.doWrite(Http11OutputBuffer > .java:225) ~[tomcat-coyote.jar:8.5.54] > at > org.apache.coyote.Response.doWrite(Response.java:600) > ~[tomcat-coyote.jar:8.5.54] > at > org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer > .java:360) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffe > r.java:841) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:74 > 6) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.jav > a:407) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:385 > ) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStr > eam.java:96) ~[catalina.jar:8.5.54] > at > org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStr > eam.java:89) ~[catalina.jar:8.5.54] > at > org.springframework.security.web.context.SaveContextOnUpdateOrErrorRes > ponseWrapper$SaveContextServletOutputStream.write(SaveContextOnUpdateO > rErrorResponseWrapper.java:453) > ~[spring-security-web-3.2.3.RELEASE.jar:3.2.3.RELEASE] > at > org.apache.catalina.filters.ExpiresFilter$XServletOutputStream.write(E > xpiresFilter.java:1006) ~[catalina.jar:8.5.54] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:803) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:784) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.writeReady(AtmosphereIn > terceptorWriter.java:92) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.invokeInterceptor(Atmos > phereInterceptorWriter.java:83) > ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterce > ptorWriter.java:69) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterce > ptorWriter.java:64) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl$Stream.write(AtmosphereRespo > nseImpl.java:957) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > at > org.atmosphere.cpr.AtmosphereResponseImpl.write(AtmosphereResponseImpl > .java:803) ~[atmosphere-runtime-2.4.24.jar:2.4.24] > ... 11 more > > Any help on ideas of what could be causing it would be greatly appreciated. Looking at the top-most portion of the stack trace, I can see that this code is being executed outside the context of a request-processing thread. Because the calls are going through the ServletOutputStream (CoyoteOutptStream.write), it's clear you are not using asynchronous request-processing. The two facts above are at odds with each other: it's not okay to hand an object from a request-processing thread (e.g. an HttpServletResponse) to another thread (which can retain references to it indefinitely) and have it interact with that object at any time. The likely error is that the NPE is being triggered by the Http110OutputBuffer having been "recycled" at the end of a request, which nulls-out its socket wrapper reference. If you try to write to the response, you will get an NPE like this. This is the best of all possible worlds. The worst possibility is that the response object has been re-used for another client, and you (a) stomp on their response and (b) introduce a privacy bug -- likely sending data to User B that should be been sent to User A. Given that Atmosphere is supposed to do exactly this -- handle asynchronous communications on behalf of an application -- I'm surprised to see this kind of error. Are you maybe implementing something alongside Atmosphere that could be causing this? -chris --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
