Bug 60718

Summary: requestDestroyed not called for asynchronous after I/O error
Product: Tomcat 8 Reporter: Brett Kail <bjkail>
Component: CatalinaAssignee: Tomcat Developers Mailing List <dev>
Severity: normal    
Priority: P2    
Version: 8.5.11   
Target Milestone: ----   
Hardware: PC   
OS: All   
Attachments: test project

Description Brett Kail 2017-02-09 13:17:01 UTC
Sequence of events:
1. Servlet "synchronously" writes an async response: ac = req.startAsync(); try { resp.getOutputStream().write(new byte[1024*1024]); } finally { ac.complete(); }
2. Client disconnects to force broken pipe (etc.): uc = new URL("...").openConnection(); uc.getInputStream().close(); uc.disconnect();

In this case, where ServletRequestListener.requestInitialized is called.  Summary of scenarios:
- Fail: the servlet writes the response synchronously after startAsync (described above)
- Fail: In Tomcat 8.5.11, the servlet writes the response truly asynchronously (with a new Thread)
- Pass: in Tomcat 8.5.6, the servlet writes the response truly asynchronously (with a new Thread)
- Pass: the servlet writes the response truly synchronously (without startAsync)
- Pass: the client reads the stream without disconnecting early (all Tomcat versions, regardless of other scenarios presented).

I think requestDestroyed should always be called.
Comment 1 Remy Maucherat 2017-02-09 17:57:58 UTC
Please try again stating more clearly what the code is (use an attachment), and the supposed failure. Please also review carefully bug 60385 it seems to apply to some of the fail scenarios described maybe (like possibly the first one).
Comment 2 Brett Kail 2017-02-09 18:39:06 UTC
Created attachment 34742 [details]
test project

I reviewed bug 60385 before opening this bug, and I do not think it is relevant.  That bug is about requestInitialized throwing an exception and therefore requestDestroyed not being called, which is reasonable.  This bug throws no exception from requestInitialized, but it forces a client error during getOutputStream().write().

I am attaching a test project that demonstrates the problem for me (on Windows at least, but earlier version of the test also failed on Linux).  Install the WAR in Tomcat, then run the main method in TestServlet.  The main method connects to four endpoints, so I would expect four "+ requestDestroyed" messages.  On Tomcat 8.5.6, there are only three (missing async=sync).  On 8.5.11, there is only one (missing all async scenarios).  Additionally, 8.5.11 has a noisy setErrorState stack trace (seems unnecessary?) and an IllegalStateException from AsyncStateMachine.asyncError.
Comment 3 Brett Kail 2017-02-10 16:53:43 UTC
It's likely the same (or a related) problem, but access log entries are not written for the failing cases either (ala bug 58702).
Comment 4 Remy Maucherat 2017-02-14 17:01:38 UTC
I think it's not going to "work" unless AsyncContextImpl.fireOnComplete calls context.fireRequestDestroyEvent(request). Or something like that.

The Tomcat code is based on the thinking that the request remains "in scope" while the async is started (so even when the Servlet's service method is no longer executed), which is what the spec seems to say (section 3.12).

Although it seems to contradict section 3.12 of the spec, it could be interpreted wrong in Tomcat and requestInitialized and requestDestroyed should simply be called around the Servlet's service method call. Right now, the code is very careful to not call requestDestroyed if async is started, and then it's obvious there are cases where it's not going to be called. And doing it like that is a duplicate for what AsyncListener does so that's rather weird, but maybe it's better for some frameworks (?). I would remove !request.isAsync() in StandardHostValve, and drop fireRequestDestroyEvent from async dispatch.

So there is likely two possibilities, but Tomcat currently does neither.
Comment 5 Brett Kail 2017-02-14 18:45:27 UTC
Tomcat doesn't appear to call AsyncListener for these scenarios either.

FWIW, I agree with the "in scope" interpretation.  I was expecting requestDestroyed to be called only after the request is no longer "in scope", not just after service returns for async.
Comment 6 Mark Thomas 2017-02-15 10:58:38 UTC
I like the idea of moving the context.fireRequestDestroyEvent(request) call to AsyncContextImpl.fireOnComplete(). That is much better aligned with what section 3.12 of the spec says.

A quick test with the current Async unit tests doesn't show any failures.

Next steps are to look into the additional scenarios presented in this bug.
Comment 7 Mark Thomas 2017-02-15 20:28:29 UTC
Many thanks for the test case. I've applied a fix to trunk (9.0.x) that addresses the issues raised by the test case. Before I back-port it, I want to look at whether the error handling needs some refactoring.
Comment 8 Mark Thomas 2017-02-15 21:42:15 UTC
Fixed in:
- trunk for 9.0.0.M18 onwards
- 8.5.x for 8.5.12 onwards
- 8.0.x for 8.0.42 onwards
- 7.0.x for 7.0.76 onwards