ExceptionHandlerExceptionResolver started to log on WARN level [SPR-17383]

[spring-projects-issues]

Lukas Krecan opened SPR-17383 and commented

This commit changed behavior of ExceptionResolver to log exceptions on WARN.

The trouble is, that we have alerts on Exceptions in logs and by default log on INFO and above so we started to get alerts for resolved exceptions.

As a workaround, we can change log level ExceptionHandlerExceptionResolver to ERROR, but we would have to change it every microservice we upgrade to newest Spring.

---

Affects: 5.1.1

Issue Links:

• AbstractHandlerExceptionResolver logs handled exceptions at WARN [SPR-17399] #21932 AbstractHandlerExceptionResolver logs handled exceptions at WARN ("is duplicated by")
• ExceptionHandlerExceptionResolver should not log propagated exceptions at warn level [SPR-14907] #19473 ExceptionHandlerExceptionResolver should not log propagated exceptions at warn level
• Consistent warn logging for handled exceptions [SPR-17178] #21714 Consistent warn logging for handled exceptions

Referenced from: commits 8e980d9, 41e6aa6, 1621125, 6ea3441

Backported to: 5.0.11, 4.3.21

[spring-projects-issues]

Rossen Stoyanchev commented

This was done based on #21714. The same commit shows how things were before. Even before the change, all @ResponseStatus exceptions and some (but not all) exceptions in DefaultHandlerExceptionResolver were logged at warn. The goal of the change was to bring consistency but it is true that for @ExceptionHandler methods we did not log anything at WARN before.

if possible I'd prefer to keep the consistency we have after the change. After all those re single line log messages at WARN, which seems appropriate for an exception that occurred and was resolved. Are the alerts perhaps capable of differentiating between WARN vs ERROR generally, as opposed to changing individual loggers? We've other places across the framework where we may log at WARN level, in addition to the ones I mentioned above. 

 

[spring-projects-issues]

Lukas Krecan commented

Usually, the logging rules in DevOps are something like this:
ERROR - needs to be solved right now
WARN - needs to be solved next working day (or eventually)
INFO - useful information
DEBUG - we need to debug something and need more data

In my opinion, resolved exceptions belong somewhere between DEBUG and INFO

[spring-projects-issues]

Rossen Stoyanchev commented

There are plenty of WARN messages across the framework. To me they are informational for production, i.e. at INFO or above, not quite an error, and something that may or may not need solving.

From a consistency point of view, at best I can see restoring the previous behavior for @ExceptionHandler methods specifically. One could argue that in such cases the controller method is aware of the exception and can log if it wants to. As opposed to all other exceptions that are handled transparently by the framework and turned into 4xx or 5xx which would still log at WARN level, as they also did before the change (but not consistently so).

[spring-projects-issues]

Lukas Krecan commented

Restoring ExceptionHandler behavior would help, thanks

[spring-projects-issues]

Dale Ogilvie commented

Likewise, we alert on WARN level messages. Hence the raising of #21932.

[spring-projects-issues]

Rossen Stoyanchev commented

@ExceptionHandler methods should now log at DEBUG level again.

[spring-projects-issues]

Rossen Stoyanchev commented

I have further rolled back the changes made for #21714, so that only the DefaultHandlerExceptionResolver logs at warn level by default, which is what the original request was for, and given that that resolver already has warn level logging for some but not all exceptions.