Hi there,

One of my applications is facing a pesky issue in Tomcat 8.0.15 dealing
with an NPE at InternalNioOutputBuffer.java:234.

I searched Bugzilla and the lists, but didn't find anything that matched
the NPE stack exactly.  Maybe I missed it.

Before I file a bug, I wanted to check here first.

Here's the stack trace:

java.lang.NullPointerException: null
at
org.apache.coyote.http11.InternalNioOutputBuffer.flushBuffer(InternalNioOutputBuffer.java:234)
~[tomcat-coyote.jar:8.0.15]
at
org.apache.coyote.http11.InternalNioOutputBuffer.addToBB(InternalNioOutputBuffer.java:189)
~[tomcat-coyote.jar:8.0.15]
at
org.apache.coyote.http11.InternalNioOutputBuffer.commit(InternalNioOutputBuffer.java:177)
~[tomcat-coyote.jar:8.0.15]
at
org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:739)
~[tomcat-coyote.jar:8.0.15]
at org.apache.coyote.Response.action(Response.java:179)
~[tomcat-coyote.jar:8.0.15]
at
org.apache.coyote.http11.AbstractOutputBuffer.doWrite(AbstractOutputBuffer.java:249)
~[tomcat-coyote.jar:8.0.15]
at org.apache.coyote.Response.doWrite(Response.java:503)
~[tomcat-coyote.jar:8.0.15]
at
org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:388)
~[catalina.jar:8.0.15]
at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:426)
~[tomcat-util.jar:8.0.15]
at
org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:424)
~[catalina.jar:8.0.15]
at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:406)
~[catalina.jar:8.0.15]
at
org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:97)
~[catalina.jar:8.0.15]
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
~[na:1.7.0_71]
at sun.nio.cs.StreamEncoder.implClose(StreamEncoder.java:316)
~[na:1.7.0_71]
at sun.nio.cs.StreamEncoder.close(StreamEncoder.java:149) ~[na:1.7.0_71]
at java.io.OutputStreamWriter.close(OutputStreamWriter.java:233)
~[na:1.7.0_71]
at foo.bar.NioNPETestServlet$ServletRunnable.run(NioNPETestServlet.java:90)
~[NioNPETestServlet$ServletRunnable.class:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[na:1.7.0_71]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[na:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[na:1.7.0_71]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_71]


I spent some time and whittled down the use case into a single servlet that
reproduces the problem quite easily with curl:

while true; do curl -v -X GET http://localhost:8080/npe; done

Here's the servlet and other goodies via Gist:

https://gist.github.com/markkolich/7cd972292418a58b5ef5

And here's a runnable version of the servlet wrapped in Tomcat 8.0.15:

http://koli.ch/x5iu

Note in addition to the NPE above, some request/responses complete, but
with a corrupted response buffer:

< HTTP/1.1 401 HTTP/1.1 401 UnauthorizeUnauthorized
* no chunk, no close, no size. Assume close to signal end
<
Server: Apache-Coyote/1.1
json;charset=utf-8
ContentContent-Type
Date: Tue,:: application/json;charset=utf-8
application/json;charset=utf-8
: 0
Content-Length: 0
: Date:

I suspect the corruption and NPE are related.

The trouble servlet is fairly vanilla, or so I think.  The service() method
is invoked, I grab a new AsyncContext for the request, and pass it off to a
runnable in a pool for processing.  The runnable sets the HTTP response
code to 401, and writes out a string of JSON.  The OutputStreamWriter used
to write the response is flushed/closed when execution leaves the
try-with-resources block.

My understanding is that closing the OutputStreamWriter here also closes
the underlying ServletOutputStream, but I don't think there's anything
wrong with that.  I'm completing the AsyncContext immediately following
that flush/close and I'm done -- I don't intend to use the
ServletOutputStream again, and even if Tomcat itself calls close() on this
same stream again later, this subsequent call to close() should have no
effect.

I also tried setting `-Dorg.apache.catalina.connector.RECYCLE_FACADES=true`
which didn't help at all.

Other details:
Java 7 u71
x64 Linux (CentOS 6.6)

If you have any thoughts on what I'm doing wrong, or if you can confirm
this is a legit bug, I'd be grateful for your input.

Thanks for your help,
-Mark

Reply via email to