Re: Same request object passed to two threads
This appears to fix the problem. We are pushing to our integration server, and hope to update our supported technologies page soon. Thanks all, Matt On Thu, Dec 8, 2016 at 1:09 AM, Mark Thomaswrote: > On 08/12/2016 07:32, Violeta Georgieva wrote: > > 2016-12-08 3:48 GMT+02:00 Matthew Bellew : > >> > >> I have narrowed this down quite a lot. This bug is caused by the same > >> Http11Processor being pushed on to the recycledProcessors stack twice. > I > >> discovered this by add a duplicates check in recycledProcessors.push() > > Kudos for tracking that down. That sort of bug can be difficult to find. > > > > > May be you are facing the issue reported here [1] > > > > Can you test with 8.5.9 that we vote currently [2]? > > +1. I was going to suggest exactly the same thing. > > One of the strack traces I trimmed included one of the cancelledKey() > calls we removed as part of the fix for [1] so I am 99% sure that it is > the root cause of this problem. > > A quick test would be to disable sendfile with useSendfile="false" on > the . However, you do really need to test with 8.5.9 to > be certain. > > Mark > > > > > Regards, > > Violeta > > > > [1] https://bz.apache.org/bugzilla/show_bug.cgi?id=60409 > > [2] http://marc.info/?l=tomcat-dev=148097070419476=2 > > > - > To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org > For additional commands, e-mail: dev-h...@tomcat.apache.org > >
Re: Same request object passed to two threads
On 08/12/2016 07:32, Violeta Georgieva wrote: > 2016-12-08 3:48 GMT+02:00 Matthew Bellew: >> >> I have narrowed this down quite a lot. This bug is caused by the same >> Http11Processor being pushed on to the recycledProcessors stack twice. I >> discovered this by add a duplicates check in recycledProcessors.push() Kudos for tracking that down. That sort of bug can be difficult to find. > May be you are facing the issue reported here [1] > > Can you test with 8.5.9 that we vote currently [2]? +1. I was going to suggest exactly the same thing. One of the strack traces I trimmed included one of the cancelledKey() calls we removed as part of the fix for [1] so I am 99% sure that it is the root cause of this problem. A quick test would be to disable sendfile with useSendfile="false" on the . However, you do really need to test with 8.5.9 to be certain. Mark > > Regards, > Violeta > > [1] https://bz.apache.org/bugzilla/show_bug.cgi?id=60409 > [2] http://marc.info/?l=tomcat-dev=148097070419476=2 - To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org
Re: Same request object passed to two threads
; be passed to the webapp on two thread concurrently, however. I'm not > > guessing about that. I added debugging code to my app and managed to stop > > in the debugger, and I could see two http-nio-8080-exec- threads with the > > same object. > > > > Matt > > > > On Tue, Dec 6, 2016 at 2:58 PM, Caldarale, Charles R < > > chuck.caldar...@unisys.com> wrote: > > > >> From: Matthew Bellew [mailto:matth...@labkey.com] > >> > Subject: Re: Same request object passed to two threads > >> > >> This should be on the users' mailing list, not dev. > >> > >> > Just realized that in the case above, I couldn't have hit the quoted > >> code, > >> > since neither call to AuthFilter.doFilter() had returned. > >> > >> > I can build and debug Tomcat, so any advice would be very welcome. > >> > >> Debug your webapp, not Tomcat. In pretty much 100% of these cases, the > >> logic in a servlet or filter of the webapp is erroneously storing the > >> reference to the request object in a static, instance, or thread-local > >> field, resulting in the wrong request object being used by another thread > >> or later in the current thread. > >> > >> You might try setting org.apache.catalina.connector.RECYCLE_FACADES to > >> see if it catches the problem. > >> http://tomcat.apache.org/tomcat-8.5-doc/config/systemprops.html#Security > >> > >> - Chuck > >> > >> > >> THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY > >> MATERIAL and is thus for use only by the intended recipient. If you > >> received this in error, please contact the sender and delete the e-mail and > >> its attachments from all computers. > >> > >> > >> - > >> To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org > >> For additional commands, e-mail: dev-h...@tomcat.apache.org > >> > >> > >
Re: Same request object passed to two threads
I have narrowed this down quite a lot. This bug is caused by the same Http11Processor being pushed on to the recycledProcessors stack twice. I discovered this by add a duplicates check in recycledProcessors.push() @SuppressWarnings("sync-override") // Size may exceed cache size a bit public boolean push(Processor processor, String source) { int cacheSize = handler.getProtocol().getProcessorCache(); boolean offer = cacheSize == -1 ? true : size.get() < cacheSize; //avoid over growing our cache or add after we have stopped boolean result = false; if (offer) { +synchronized (this) +{ +for (int i=0 ; i<=index ; i++) +assert processor != stack[i]; result = super.push(processor); +} if (result) { size.incrementAndGet(); } } if (!result) handler.unregister(processor); return result; } A bit more hacking showed that the processor would be pushed first via ConnectionHandler.release(*SocketWrapperBase*) called from Pooler.cancelledKey() (NOTE: AbstractProtocolJava line numbers don't line up with 8.5.8 because of debug code) at org.apache.coyote.AbstractProtocol$RecycledProcessors.push(AbstractProtocol.java:1116) at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1002) at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1016) at org.apache.tomcat.util.net.NioEndpoint$Poller.cancelledKey(NioEndpoint.java:730) at org.apache.tomcat.util.net.NioEndpoint$Poller.processSendfile(NioEndpoint.java:966) at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.processSendfile(NioEndpoint.java:1305) at org.apache.coyote.http11.Http11Processor.breakKeepAliveLoop(Http11Processor.java:1611) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:852) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745) The second push of the same processor happens via the "normal" ConnectionHandler.release(*Processor*) called from ConnectionHandler.process() at org.apache.coyote.AbstractProtocol$ConnectionHandler.release(AbstractProtocol.java:1002) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:927) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) - locked <0x62c2> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745) I don't know understand the whole processSendFile() and state=SENDFILE logic. One suspicious thing comparing the two stack traces is that ConnectionHandler.process() does not check the return result from connections.remove(). Maybe a) ConnectionHandler.process() should only call release(processor) if the connections.remove(socket)==processor? or b) release(socket) shouldn't call recycledProcessors.push()? Matt On Tue, Dec 6, 2016 at 3:53 PM, Matthew Bellew <matth...@labkey.com> wrote: > Thanks for the pointer to org.apache.catalina.connector.RECYCLE_FACADES. > I will try running our integration server with that set both ways and > compare. > > I don't see how an application bug could cause the same RequestFacade to > be passed to the webapp on two thread concurrently, however. I'm not > guessing about that. I added debugging code to my app and managed to stop > in the debugger, and I could see two http-nio-8080-exec- threads with the > same object. > > Matt > > On Tue, Dec 6, 2016 at 2:58 PM, Caldarale, Charles R < > chuck.caldar...@unisys.com> wrote: > >> From: Matthew Bellew [mailto:matth...@labkey.com] >> > Subject: Re: Same request object passed to two threads >> >> This should be on the users' mailing list, not dev. >> >> > Just realized that in the case above, I couldn't have hit the quoted >> code, >> > since neither call to AuthFilter.doFilter() had returned. >> >> > I can build and debug Tomcat, so any advice
Re: Same request object passed to two threads
Thanks for the pointer to org.apache.catalina.connector.RECYCLE_FACADES. I will try running our integration server with that set both ways and compare. I don't see how an application bug could cause the same RequestFacade to be passed to the webapp on two thread concurrently, however. I'm not guessing about that. I added debugging code to my app and managed to stop in the debugger, and I could see two http-nio-8080-exec- threads with the same object. Matt On Tue, Dec 6, 2016 at 2:58 PM, Caldarale, Charles R < chuck.caldar...@unisys.com> wrote: > From: Matthew Bellew [mailto:matth...@labkey.com] > > Subject: Re: Same request object passed to two threads > > This should be on the users' mailing list, not dev. > > > Just realized that in the case above, I couldn't have hit the quoted > code, > > since neither call to AuthFilter.doFilter() had returned. > > > I can build and debug Tomcat, so any advice would be very welcome. > > Debug your webapp, not Tomcat. In pretty much 100% of these cases, the > logic in a servlet or filter of the webapp is erroneously storing the > reference to the request object in a static, instance, or thread-local > field, resulting in the wrong request object being used by another thread > or later in the current thread. > > You might try setting org.apache.catalina.connector.RECYCLE_FACADES to > see if it catches the problem. > http://tomcat.apache.org/tomcat-8.5-doc/config/systemprops.html#Security > > - Chuck > > > THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY > MATERIAL and is thus for use only by the intended recipient. If you > received this in error, please contact the sender and delete the e-mail and > its attachments from all computers. > > > - > To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org > For additional commands, e-mail: dev-h...@tomcat.apache.org > >
RE: Same request object passed to two threads
From: Matthew Bellew [mailto:matth...@labkey.com] > Subject: Re: Same request object passed to two threads This should be on the users' mailing list, not dev. > Just realized that in the case above, I couldn't have hit the quoted code, > since neither call to AuthFilter.doFilter() had returned. > I can build and debug Tomcat, so any advice would be very welcome. Debug your webapp, not Tomcat. In pretty much 100% of these cases, the logic in a servlet or filter of the webapp is erroneously storing the reference to the request object in a static, instance, or thread-local field, resulting in the wrong request object being used by another thread or later in the current thread. You might try setting org.apache.catalina.connector.RECYCLE_FACADES to see if it catches the problem. http://tomcat.apache.org/tomcat-8.5-doc/config/systemprops.html#Security - Chuck THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers. - To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org For additional commands, e-mail: dev-h...@tomcat.apache.org
Re: Same request object passed to two threads
Just realized that in the case above, I couldn't have hit the quoted code, since neither call to AuthFilter.doFilter() had returned. I can build and debug Tomcat, so any advice would be very welcome. Matt On Tue, Dec 6, 2016 at 2:20 PM, Matthew Bellewwrote: > I have an intermittent bug that I've been trying to trying to track down > for a long time. The symptom is that the same tomcat request object is > being processed by two different threads. The symptom is a random crash > when one thread returns and recycles the request, and the other thread > access the request object, usually causing an NPE. > > Note, there are no background threads going on here. I see my top-most > filter AuthFilter.doFilter() is being called once with a Tomcat > RequestFacade object, and before that thread returns, AuthFilter.doFilter() > is called again on another thread with the exact == RequestFacade object. > > Google hasn't given me any leads (beyond "don't pass a request do another > thread". I'm not). > > My suspicion at this point centers around this code, though I have not > spent a much time in Tomcat internals. In Tomcat 8.5.8 > AbstractProtocol.ConnectionHandler.process() > around line 889. > > wrapper.registerReadInterest(); > } else if (state == SocketState.SENDFILE) { > // Sendfile in progress. If it fails, the socket will be > // closed. If it works, the socket will be re-added to the > // poller > connections.remove(socket); > Thread t = threads.remove(socket); assert t == Thread.currentThread(); > release(processor); > } else if (state == SocketState.UPGRADED) { > // Don't add sockets back to the poller if this was a > > My reading of this is that when state == SENDFILE, the request is not > complete in some sense. However, the processor is being released to be > recycled. Is this OK for the processor to be picked up by another thread > at this point? > > Thanks for any help, > Matt >
Same request object passed to two threads
I have an intermittent bug that I've been trying to trying to track down for a long time. The symptom is that the same tomcat request object is being processed by two different threads. The symptom is a random crash when one thread returns and recycles the request, and the other thread access the request object, usually causing an NPE. Note, there are no background threads going on here. I see my top-most filter AuthFilter.doFilter() is being called once with a Tomcat RequestFacade object, and before that thread returns, AuthFilter.doFilter() is called again on another thread with the exact == RequestFacade object. Google hasn't given me any leads (beyond "don't pass a request do another thread". I'm not). My suspicion at this point centers around this code, though I have not spent a much time in Tomcat internals. In Tomcat 8.5.8 AbstractProtocol.ConnectionHandler.process() around line 889. wrapper.registerReadInterest(); } else if (state == SocketState.SENDFILE) { // Sendfile in progress. If it fails, the socket will be // closed. If it works, the socket will be re-added to the // poller connections.remove(socket); Thread t = threads.remove(socket); assert t == Thread.currentThread(); release(processor); } else if (state == SocketState.UPGRADED) { // Don't add sockets back to the poller if this was a My reading of this is that when state == SENDFILE, the request is not complete in some sense. However, the processor is being released to be recycled. Is this OK for the processor to be picked up by another thread at this point? Thanks for any help, Matt