Bug 62797

Summary: Client aborts are being written as 500 instead of 200
Product: Tomcat 9 Reporter: zikfat
Component: CatalinaAssignee: Tomcat Developers Mailing List <dev>
Severity: normal CC: gregk
Priority: P2    
Version: 9.0.10   
Target Milestone: -----   
Hardware: PC   
OS: Linux   
Attachments: patch with a potential fix

Description zikfat 2018-10-02 22:04:05 UTC
Created attachment 36187 [details]
patch with a potential fix

After upgrading from Tomcat 8.0.36 to 9.0.10 I noticed new 500 errors showing up in my access logs without any associated exceptions in the application log. I believe these are caused by clients aborting their connection to the server, and that the upgrade in Tomcat versions caused the logged status code for these requests to change from 200 to 500.

Digging through Tomcat history, it looks like bug 60718 introduced an issue like this in 9.0.0.M18. After the discussion at https://markmail.org/message/4cxpwmxhtgnrwh7n it was decided that 200s were the "least bad" status for client aborts. The commit at https://github.com/apache/tomcat/commit/3b51ec4d35546a0244f4f7c4ec6c57ebfa5dd883 was made to fix this for 9.0.0.M22 by stopping IOExceptions from setting a 500 status code on the response.

When I trace through the code I see the fix from 9.0.0.M22 is preventing the 500 status from being set initially when the server first encounters an error trying to write to the client, but the 500 status is getting set later (but still before access log lines are written) as a side-effect of the ErrorReportValve.

The ErrorReportValve's invoke method has this line:

response.getCoyoteResponse().action(ActionCode.CLOSE_NOW, null)

Which results in the AbstractProcessor.setErrorState method getting called with a null throwable. This gets past the IOException guard added in 9.0.0.M22 and sets the 500 status on the response.

Attached is a patch which has ErrorReportValve pass through the Request's Throwable on that line. In my testing this seems to fix the issue.
Comment 1 Remy Maucherat 2018-10-12 09:31:57 UTC
This makes sense to me. The fix will be in 9.0.13, 8.5.35 and 7.0.92.