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(ModelStatusConsumer.java:145)
[classes/:2019.3.4-9-1]
at
org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:1404)
[activemq-client-5.15.10.jar:5.15.10]
at
org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:131)
[activemq-client-5.15.10.jar:5.15.10]
at
org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:202)
[activemq-client-5.15.10.jar:5.15.10]
at
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
[activemq-client-5.15.10.jar:5.15.10]
at
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
[activemq-client-5.15.10.jar:5.15.10]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java: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(AtmosphereInterceptorWriter.java:92)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.invokeInterceptor(AtmosphereInterceptorWriter.java:83)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterceptorWriter.java:69)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterceptorWriter.java:64)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereResponseImpl$Stream.write(AtmosphereResponseImpl.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(ChunkedOutputFilter.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(OutputBuffer.java:841)
~[catalina.jar:8.5.54]
at
org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:746)
~[catalina.jar:8.5.54]
at
org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java: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(CoyoteOutputStream.java:96)
~[catalina.jar:8.5.54]
at
org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:89)
~[catalina.jar:8.5.54]
at
org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$SaveContextServletOutputStream.write(SaveContextOnUpdateOrErrorResponseWrapper.java:453)
~[spring-security-web-3.2.3.RELEASE.jar:3.2.3.RELEASE]
at
org.apache.catalina.filters.ExpiresFilter$XServletOutputStream.write(ExpiresFilter.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(AtmosphereInterceptorWriter.java:92)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.invokeInterceptor(AtmosphereInterceptorWriter.java:83)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterceptorWriter.java:69)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereInterceptorWriter.write(AtmosphereInterceptorWriter.java:64)
~[atmosphere-runtime-2.4.24.jar:2.4.24]
at
org.atmosphere.cpr.AtmosphereResponseImpl$Stream.write(AtmosphereResponseImpl.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
