Created attachment 34876 [details] Some pieces of the full trace showing the issue This is a similar report to https://bz.apache.org/bugzilla/show_bug.cgi?id=58646 but whatever fix was done in that case does not prevent this issue. Basic outline: 1. thread http-nio-8080-exec-1 processes a request that will result in send file. It pops Http11Processor@8dc1458 from recycledProcessors 2. The send file action is completed in thread http-nio-8080-ClientPoller-0. Then that thread is done, it pushes Http11Processor@8dc1458 onto recycledProcessors 3. A few milliseconds later, http-nio-8080-exec-1 also pushes Http11Processor@8dc1458 onto recycledProcessors, so now that one processor is in the list of recycledProcessors twice 4. Eventually, two nio exec threads both pop that one instance off of recycledProcessors 4A. The second thread to use it throws 24-Mar-2017 12:08:08.093 INFO [http-nio-8080-exec-1] org.apache.coyote.http11.Http11Processor.service Error parsing HTTP request header Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level. java.lang.IllegalStateException: Unexpected state: headers already parsed. Buffer not recycled? at org.apache.coyote.http11.Http11InputBuffer.parseHeaders(Http11InputBuffer.java:554) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:683) 4B. The first thread, which completes after the second one, throws 24-Mar-2017 12:08:08.833 SEVERE [http-nio-8080-exec-7] org.apache.coyote.http11.Http11Processor.service Error processing request java.lang.NullPointerException at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:389) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:783) and then 24-Mar-2017 12:08:08.849 SEVERE [http-nio-8080-exec-7] org.apache.coyote.http11.Http11Processor.endRequest Error finishing response java.lang.NullPointerException at org.apache.coyote.http11.Http11OutputBuffer.commit(Http11OutputBuffer.java:351) at org.apache.coyote.http11.Http11Processor.prepareResponse(Http11Processor.java:1288) at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:254) at org.apache.coyote.http11.Http11Processor.endRequest(Http11Processor.java:1457) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:823)
To me, there are two separate issues here: 1. The logic for pushing the processor back in send file case has some flaw. 2. RecycledProcessors should protect against the same instance being in the stack more than once, as a defense against this flaw or any future flaws that result in mistakenly putting the same processor in twice.
Thanks for the report and especially the debug logs. I was able to pin-point the root cause very quickly from those. Are you able to build Tomcat from svn in order to confirm a fix?
i haven't before, but I am sure I could :) Please point me at BUILD instructions.
These are the instructions for 9.0.x https://svn.apache.org/viewvc/tomcat/trunk/BUILDING.txt?view=markup 8.5.x is very similar, just a different svn path and a different minimum Java version. Both 9.0.x and 8.5.x have the fix. I'm currently working on a back-port to 8.0.x.
thanks for the info. Can you point me to the commit diff? Just curious.
r1788544 (for 9.0.x)
FYI, minor typo in changelog subsequent requests experiencing and <code>IllegalStateException</code>. "and" -> "an"
8.0.x and earlier are not affected. This bug was introduced by the refactoring in 8.5.x onwards.
Created attachment 34877 [details] Recoded RecycledProcessors The problem does not recur using the version built from trunk! Thanks for the rapid turnaround. I guess it will be a month or two before this is part of an official release? FYI, I had also prevented the problem by re-coding the RecycledProcessors class to check for existence before pushing onto the stack. This was quick and dirty and would not scale, but food for thought.
We'll probably start the release process next week. It is normally started around the beginning of the every month but the first week of April is looking busy for me. We could delay it but there is enough in the changelog to justify a release.
(In reply to Andrew Garland from comment #9) > Created attachment 34877 [details] > Recoded RecycledProcessors > > The problem does not recur using the version built from trunk! Thanks for > the rapid turnaround. I guess it will be a month or two before this is part > of an official release? > > FYI, I had also prevented the problem by re-coding the RecycledProcessors > class to check for existence before pushing onto the stack. This was quick > and dirty and would not scale, but food for thought. And we're not going to do that :)
Fixed in: - trunk for 9.0.0.M19 onwards - 8.5.x for 8.5.13 onwards
Who can provide the test code for the recurrence of this bug