|Summary:||NullPointerException in org.apache.catalina.core.AsyncContextImpl.doInternalComplete|
|Product:||Tomcat 7||Reporter:||Kevin <kevin>|
|Component:||Catalina||Assignee:||Tomcat Developers Mailing List <dev>|
Servlet used to reproduce the problem
Patch to make some private fields final
Description Kevin 2010-09-04 23:16:09 UTC
Hi, I'm running Tomcat trunk (revision 992708, 2010-09-03) and I'm hitting an async servlet (see attached) with Apache Bench, and every once in a while I see a NullPointerException in org.apache.catalina.core.AsyncContextImpl.doInternalComplete: Sep 4, 2010 8:09:39 PM org.apache.catalina.core.AsyncContextImpl doInternalDispatch FINE: TIMING OUT! Sep 4, 2010 8:09:40 PM org.apache.catalina.core.AsyncContextImpl doInternalDispatch FINE: TIMING OUT! Sep 4, 2010 8:09:40 PM org.apache.catalina.core.AsyncContextImpl doInternalComplete SEVERE: Throwable occurred: java.lang.NullPointerException at org.apache.catalina.core.AsyncContextImpl.doInternalComplete(AsyncContextImpl.java:384) at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:327) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:238) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:201) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:163) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:108) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:557) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:301) at org.apache.coyote.http11.Http11Processor.asyncDispatch(Http11Processor.java:333) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:258) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:257) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920) at java.lang.Thread.run(Thread.java:736)
Comment 1 Kevin 2010-09-04 23:24:22 UTC
Created attachment 25989 [details] Servlet used to reproduce the problem
Comment 2 Mark Thomas 2010-09-05 17:10:09 UTC
The state changes in AsyncContextImpl aren't atomic so I think what you are seeing is the result of multiple parallel calls to doInternalComplete(). Am I correct in thinking this error is fairly rare?
Comment 3 Kevin 2010-09-05 17:42:02 UTC
(In reply to comment #2) > The state changes in AsyncContextImpl aren't atomic so I think what you are > seeing is the result of multiple parallel calls to doInternalComplete(). Am I > correct in thinking this error is fairly rare? Yes, it is rare. The reason I reported this is that I'm load testing this servlet (well, my real servlet, but this one just to repro the problem), and every once in a while I get a 200 or 500 response that takes over 10 seconds whereas the average is half a second (using AccessLogValve %D to see this). I ran with tracing and noticed this NPE and thought maybe it's somehow related to the sporadic long request, but I don't know if it's root cause. Also, it is preceded by the "TIMING OUT!" entry, so maybe this NPE is just a side effect of the timeout?
Comment 4 Mark Thomas 2010-09-07 09:03:57 UTC
I've been able to spend some time looking at this. It is very easy to reproduce on a multi-core machine with relatively low numbers of requests and concurrency. There is definitely a threading issue at the heart of this. I need to dig deeper to find out exactly what the root cause is.
Comment 5 Kevin 2010-09-07 10:46:43 UTC
(In reply to comment #4) > I've been able to spend some time looking at this. It is very easy to reproduce > on a multi-core machine with relatively low numbers of requests and > concurrency. > > There is definitely a threading issue at the heart of this. I need to dig > deeper to find out exactly what the root cause is. Thanks Mark.
Comment 6 Sebb 2010-09-13 12:13:42 UTC
Created attachment 26022 [details] Patch to make some private fields final They are probably not a cause of the synch. issues, but it would not harm to make these fields final.
Comment 7 Mark Thomas 2010-09-27 08:14:41 UTC
This has been fixed in trunk and will be included in 7.0.3. Thanks for uncovering this. It highlighted a bunch of issues with the async implementation that are hopefully now fixed.