Errors from a MethodInvokingJob are only logged at WARN/INFO level (and twice...) [SPR-4630]

[spring-projects-issues]

Martin Probst opened SPR-4630 and commented

When a MethodInvokingJob scheduled by Quartz throws an exception, the error is logged twice, once at WARN level by the MethodInvokingJob wrapper, and once at INFO by Quartz.

This is because the MethodInvokingJob catches all exceptions thrown by the invoked method (InvocationTargetExceptions), and then re-throws them as JobExecutionExceptions. Quartz apparently considers those to be "expected exceptions" that are used for scheduling purposes, and as such they are only logged as INFO.

Spring's MethodInvokingJob should probably find out if the thrown exceptions was a runtime exception, and re-throw it, and simply wrap checked exceptions in an appropriate RuntimeException and rethrow them. JobExecutionExceptions are apparently reserved for other purposes.

Also, you should probably not log an exception that you are re-throwing anyways, that only gives duplicate log entries, making a potential problem harder to find.

---

Affects: 2.0.8, 2.5.1

Backported to: 2.0.9

[spring-projects-issues]

Martin Probst commented

Of course this is your decision, but I intentionally marked this as a bug. With this behaviour, errors that happen in scheduled tasks will not get logged in many production environments, and will not cause e.g. error emails being sent. That is IMHO a bug, and it might even be quite nasty with errors going unnoticed.

[spring-projects-issues]

Juergen Hoeller commented

Agreed - you've got a point there.

I'm also scheduling this for a fix in the Spring 2.0 maintenance branch.

Juergen

[spring-projects-issues]

Juergen Hoeller commented

I've revised MethodInvokingJob to rethrow invocation exceptions as JobMethodInvocationFailedException (a custom RuntimeException), triggering error logging by Quartz. MethodInvokingJob does not perform own warn logging there anymore. I've also revised DelegatingJob and MethodInvokingRunnable accordingly, for consistent error level logging.

This will be available in tonight's 2.5.3 snapshot (http://static.springframework.org/downloads/nightly/snapshot-download.php?project=SPR). Please give it a try and let me know whether it works for you...

As for the 2.0.9 release, I've only raised MethodInvokingJob's own log level to error there while still throwing JobExecutionExceptions. The reasoning there is as little impact on existing usage as possible, which doesn't allow for changing to a different type of Quartz exception. So there will still be double logging on 2.0.9 but at least one of them is at error level...

Juergen