You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Thomas Eliassen <th...@scout24.com> on 2017/06/06 14:08:27 UTC
Re: Change of status code for ClientAbortExceptions - bug?
Is there some way to avoid having it logged as a 500 in the access log then?
ClientAbortExceptions are so frequent that it really pollutes the access logs, drowns out 500s actually caused by the server side application, and makes monitoring and debugging based on the access logging a lot harder.
I'll also note that e.g. Jetty logs a 200 on ClientAbortExceptions.
--
Another one I failed to send to the list first time around...
On 29/05/17 08:26, Thomas Eliassen wrote:
> Hi,
>
> Since https://bz.apache.org/bugzilla/show_bug.cgi?id=60718 (r1783148 in tc8.5.x), ClientAbortExceptions are logged in the access log as status 500, changed from the previous status 200.
>
> Is this actually the desired behaviour? It doesn't seem appropriate to log a 500 as this isn't necessarily a server error.
The server has no way of knowing for sure whether the request processing
completed cleanly and then failed when the completed response was being
written or if the exception caused the processing to abort half-way through.
A 200 response certainly doesn't look to be correct.
None of the 4xx codes look to be appropriate.
That does, pretty much, leave the 500 code which does not seem an
unreasonable option.
> Also, the error isn't being logged to catalina.log using the default logging.properties, which for a 500 error seems wrong.
I suspect if you enable debug logging you'll see it. It doesn't make
sense to log user triggered exceptions by default.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Change of status code for ClientAbortExceptions - bug?
Posted by Mark Thomas <ma...@apache.org>.
On 06/06/17 23:11, Konstantin Kolinko wrote:
> 2017-06-07 0:10 GMT+03:00 Mark Thomas <ma...@apache.org>:
>> On 06/06/17 15:08, Thomas Eliassen wrote:
>>>
>>> Is there some way to avoid having it logged as a 500 in the access log then?
>>
>> At the moment, no. And my preference is to avoid creating new
>> configuration options unless we have to.
>>
>>> ClientAbortExceptions are so frequent that it really pollutes the access logs, drowns out 500s actually caused by the server side application, and makes monitoring and debugging based on the access logging a lot harder.
>>
>> Fair point.
>>
>>> I'll also note that e.g. Jetty logs a 200 on ClientAbortExceptions.
>>
>> I've been looking at RFC 7231 in more detail.
>>
>> None of the status codes are ideal. Of course, they are intended for the
>> client which in this case is never going to see the status code anyway
>> but still...
>>
>> The general description of 2xx codes looks to be appropriate:
>> "... the client's request was successfully received, understood, and
>> accepted."
>>
>> 200 doesn't seem right since:
>> "... the request has succeeded."
>>
>> 202 could be better since:
>> "... the request has been accepted for processing, but the processing
>> has not been completed."
>> but the intention behind 202 is very different so using it in this case
>> seems wrong.
>>
>> None of the other 2xx codes seem to be a match at all.
>>
>> The 4xx codes are another possibility:
>> "... 4xx (Client Error) class of status code indicates that the client
>> seems to have erred."
>>
>> Of those only 400 is a possible match.
>> "... the server cannot or will not process the request due to something
>> that is perceived to be a client error."
>>
>> The 5xx codes are also possible:
>> "... the server is aware that it has erred or is incapable of performing
>> the requested method"
>>
>> With 500 being the best match in that case:
>> "... the server encountered an unexpected condition that prevented it
>> from fulfilling the request."
>>
>> You have already explained why using 500 is a problem. 400 suffers from
>> a similar issue. Which brings us back to 200 which doesn't seem right
>> either.
>>
>> I think we are going to have to choose a "least bad" option here. Given
>> that Tomcat has used 200 in the past and that there is the option to add
>> %{javax.servlet.error.exception}r to the access log I think reverting
>> the change to the status code is the best (well, least bad) option here.
>>
>> I'll get that done shortly.
>
> I think that it makes sense to log the status code that was actually
> sent on the first line of the response.
>
> If "200" was sent to browser, it is better to log "200", not "500".
Note: It is possible that no status code was sent e,g, if the client
disconnected before the response was committed.
The restored behaviour is that the access log will contain whatever
status code the application set.
>
> As an idea:
>
> In Apache HTTPD there is an option in their access log format to log
> connection status: "%X"
>
> http://httpd.apache.org/docs/2.4/mod/mod_log_config.html#formats
>
> "%X":
> Connection status when response is completed:
> X = Connection aborted before the response completed.
> + = Connection may be kept alive after the response is sent.
> - = Connection will be closed after the response is sent.
That is an excellent idea. I'll add a BZ entry for that.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Change of status code for ClientAbortExceptions - bug?
Posted by Konstantin Kolinko <kn...@gmail.com>.
2017-06-07 0:10 GMT+03:00 Mark Thomas <ma...@apache.org>:
> On 06/06/17 15:08, Thomas Eliassen wrote:
>>
>> Is there some way to avoid having it logged as a 500 in the access log then?
>
> At the moment, no. And my preference is to avoid creating new
> configuration options unless we have to.
>
>> ClientAbortExceptions are so frequent that it really pollutes the access logs, drowns out 500s actually caused by the server side application, and makes monitoring and debugging based on the access logging a lot harder.
>
> Fair point.
>
>> I'll also note that e.g. Jetty logs a 200 on ClientAbortExceptions.
>
> I've been looking at RFC 7231 in more detail.
>
> None of the status codes are ideal. Of course, they are intended for the
> client which in this case is never going to see the status code anyway
> but still...
>
> The general description of 2xx codes looks to be appropriate:
> "... the client's request was successfully received, understood, and
> accepted."
>
> 200 doesn't seem right since:
> "... the request has succeeded."
>
> 202 could be better since:
> "... the request has been accepted for processing, but the processing
> has not been completed."
> but the intention behind 202 is very different so using it in this case
> seems wrong.
>
> None of the other 2xx codes seem to be a match at all.
>
> The 4xx codes are another possibility:
> "... 4xx (Client Error) class of status code indicates that the client
> seems to have erred."
>
> Of those only 400 is a possible match.
> "... the server cannot or will not process the request due to something
> that is perceived to be a client error."
>
> The 5xx codes are also possible:
> "... the server is aware that it has erred or is incapable of performing
> the requested method"
>
> With 500 being the best match in that case:
> "... the server encountered an unexpected condition that prevented it
> from fulfilling the request."
>
> You have already explained why using 500 is a problem. 400 suffers from
> a similar issue. Which brings us back to 200 which doesn't seem right
> either.
>
> I think we are going to have to choose a "least bad" option here. Given
> that Tomcat has used 200 in the past and that there is the option to add
> %{javax.servlet.error.exception}r to the access log I think reverting
> the change to the status code is the best (well, least bad) option here.
>
> I'll get that done shortly.
I think that it makes sense to log the status code that was actually
sent on the first line of the response.
If "200" was sent to browser, it is better to log "200", not "500".
As an idea:
In Apache HTTPD there is an option in their access log format to log
connection status: "%X"
http://httpd.apache.org/docs/2.4/mod/mod_log_config.html#formats
"%X":
Connection status when response is completed:
X = Connection aborted before the response completed.
+ = Connection may be kept alive after the response is sent.
- = Connection will be closed after the response is sent.
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Change of status code for ClientAbortExceptions - bug?
Posted by Mark Thomas <ma...@apache.org>.
On 21/08/17 18:22, icyerasor wrote:
> markt wrote
>> On 06/06/17 15:08, Thomas Eliassen wrote:
>> ...
>>
>> I think we are going to have to choose a "least bad" option here. Given
>> that Tomcat has used 200 in the past and that there is the option to add
>> %{javax.servlet.error.exception}r to the access log I think reverting
>> the change to the status code is the best (well, least bad) option here.
>>
>> I'll get that done shortly.
>>
>> Mark
>
> I saw that the change was kind of reverted with Revision 1797829 in
> http://svn.apache.org/repos/asf/tomcat/tc8.5.x/trunk/java/org/apache/coyote/AbstractProcessor.java
> - but it does not work for me.
Steps to reproduce please.
Mark
> When I stop a request from within the client the method is called with an
> ErrorState.CLOSE_NOW and t=null. Thus !(t instanceof IOException) is true
> and the status will be set to 500 again.
>
> Maybe it would make more sense to check for
> if (response.getStatus() < 400 && errorState.isIoAllowed())
> // then set to 500, otherwise it was probably a client disconnect
>
> I also saw that with 8.5.20 the %X accessLog format was added, which I might
> be able to use to differentiate between "real" 500 server-errors and client
> disconnects.
>
> Best Regards
> Andreas
>
>
>
>
> --
> View this message in context: http://tomcat.10.x6.nabble.com/Change-of-status-code-for-ClientAbortExceptions-bug-tp5063738p5066604.html
> Sent from the Tomcat - User mailing list archive at Nabble.com.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Change of status code for ClientAbortExceptions - bug?
Posted by icyerasor <fe...@web.de>.
markt wrote
> On 06/06/17 15:08, Thomas Eliassen wrote:
> ...
>
> I think we are going to have to choose a "least bad" option here. Given
> that Tomcat has used 200 in the past and that there is the option to add
> %{javax.servlet.error.exception}r to the access log I think reverting
> the change to the status code is the best (well, least bad) option here.
>
> I'll get that done shortly.
>
> Mark
I saw that the change was kind of reverted with Revision 1797829 in
http://svn.apache.org/repos/asf/tomcat/tc8.5.x/trunk/java/org/apache/coyote/AbstractProcessor.java
- but it does not work for me.
When I stop a request from within the client the method is called with an
ErrorState.CLOSE_NOW and t=null. Thus !(t instanceof IOException) is true
and the status will be set to 500 again.
Maybe it would make more sense to check for
if (response.getStatus() < 400 && errorState.isIoAllowed())
// then set to 500, otherwise it was probably a client disconnect
I also saw that with 8.5.20 the %X accessLog format was added, which I might
be able to use to differentiate between "real" 500 server-errors and client
disconnects.
Best Regards
Andreas
--
View this message in context: http://tomcat.10.x6.nabble.com/Change-of-status-code-for-ClientAbortExceptions-bug-tp5063738p5066604.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Change of status code for ClientAbortExceptions - bug?
Posted by Mark Thomas <ma...@apache.org>.
On 06/06/17 15:08, Thomas Eliassen wrote:
>
> Is there some way to avoid having it logged as a 500 in the access log then?
At the moment, no. And my preference is to avoid creating new
configuration options unless we have to.
> ClientAbortExceptions are so frequent that it really pollutes the access logs, drowns out 500s actually caused by the server side application, and makes monitoring and debugging based on the access logging a lot harder.
Fair point.
> I'll also note that e.g. Jetty logs a 200 on ClientAbortExceptions.
I've been looking at RFC 7231 in more detail.
None of the status codes are ideal. Of course, they are intended for the
client which in this case is never going to see the status code anyway
but still...
The general description of 2xx codes looks to be appropriate:
"... the client's request was successfully received, understood, and
accepted."
200 doesn't seem right since:
"... the request has succeeded."
202 could be better since:
"... the request has been accepted for processing, but the processing
has not been completed."
but the intention behind 202 is very different so using it in this case
seems wrong.
None of the other 2xx codes seem to be a match at all.
The 4xx codes are another possibility:
"... 4xx (Client Error) class of status code indicates that the client
seems to have erred."
Of those only 400 is a possible match.
"... the server cannot or will not process the request due to something
that is perceived to be a client error."
The 5xx codes are also possible:
"... the server is aware that it has erred or is incapable of performing
the requested method"
With 500 being the best match in that case:
"... the server encountered an unexpected condition that prevented it
from fulfilling the request."
You have already explained why using 500 is a problem. 400 suffers from
a similar issue. Which brings us back to 200 which doesn't seem right
either.
I think we are going to have to choose a "least bad" option here. Given
that Tomcat has used 200 in the past and that there is the option to add
%{javax.servlet.error.exception}r to the access log I think reverting
the change to the status code is the best (well, least bad) option here.
I'll get that done shortly.
Mark
>
> --
>
> Another one I failed to send to the list first time around...
>
> On 29/05/17 08:26, Thomas Eliassen wrote:
>> Hi,
>>
>> Since https://bz.apache.org/bugzilla/show_bug.cgi?id=60718 (r1783148 in tc8.5.x), ClientAbortExceptions are logged in the access log as status 500, changed from the previous status 200.
>>
>> Is this actually the desired behaviour? It doesn't seem appropriate to log a 500 as this isn't necessarily a server error.
>
> The server has no way of knowing for sure whether the request processing
> completed cleanly and then failed when the completed response was being
> written or if the exception caused the processing to abort half-way through.
>
> A 200 response certainly doesn't look to be correct.
>
> None of the 4xx codes look to be appropriate.
>
> That does, pretty much, leave the 500 code which does not seem an
> unreasonable option.
>
>> Also, the error isn't being logged to catalina.log using the default logging.properties, which for a 500 error seems wrong.
>
> I suspect if you enable debug logging you'll see it. It doesn't make
> sense to log user triggered exceptions by default.
>
> Mark
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org