From 04692f7b9b8461cf5775cd41e88dc9bf53b0506d Mon Sep 17 00:00:00 2001 From: Rune Flobakk Date: Thu, 30 May 2024 21:08:05 +0200 Subject: [PATCH] fix: Mention exception in log message on failures (#497) A small suggestion for some improved ergonomics when reading log output from db-scheduler in the case of failures. I always find it effective to include a small "summary" of any caught exception in the actual log message. Often this will allow me to pinpoint the error at hand without needing to look into the stacktrace of the logger event. (But this is still possible of course, as before) Logs when exceptions propagates all the way back to db-scheduler can typically look like this: db-scheduler-failure-log This PR will change the log message to mention the actual exception which was caught in the log message: > Unhandled exception IllegalArgumentException: 'Illegal character in path at index 9: [replace with URL]' during execution of task with name 'my-task-name'. Treating as failure. ## Fixes No existing issue, I suspect. Please consider this PR the issue, with a suggested fix, all bundled nicely together :) ## Reminders - [x] Added/ran automated tests (existing tests have been run) - [x] Update README and/or examples (no update necessary, I think) - [x] Ran `mvn spotless:apply` --- cc @kagkarlsson --- .../kagkarlsson/scheduler/ExceptionUtils.java | 29 +++++++++++++++++++ .../kagkarlsson/scheduler/ExecutePicked.java | 13 +++++---- .../scheduler/ExceptionUtilsTest.java | 28 ++++++++++++++++++ 3 files changed, 65 insertions(+), 5 deletions(-) create mode 100644 db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExceptionUtils.java create mode 100644 db-scheduler/src/test/java/com/github/kagkarlsson/scheduler/ExceptionUtilsTest.java diff --git a/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExceptionUtils.java b/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExceptionUtils.java new file mode 100644 index 00000000..1eb6a4ae --- /dev/null +++ b/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExceptionUtils.java @@ -0,0 +1,29 @@ +/* + * Copyright (C) Gustav Karlsson + * + *

Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file + * except in compliance with the License. You may obtain a copy of the License at + * + *

http://www.apache.org/licenses/LICENSE-2.0 + * + *

Unless required by applicable law or agreed to in writing, software distributed under the + * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either + * express or implied. See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.github.kagkarlsson.scheduler; + +final class ExceptionUtils { + + static String describe(Throwable t) { + if (t == null) { + return null; + } + + String typeDescription = t.getClass().getSimpleName(); + String message = t.getMessage(); + return typeDescription + (message != null ? ": '" + message + "'" : ""); + } + + private ExceptionUtils() {} +} diff --git a/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExecutePicked.java b/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExecutePicked.java index c5564d15..fc2d3f3f 100644 --- a/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExecutePicked.java +++ b/db-scheduler/src/main/java/com/github/kagkarlsson/scheduler/ExecutePicked.java @@ -13,6 +13,8 @@ */ package com.github.kagkarlsson.scheduler; +import static com.github.kagkarlsson.scheduler.ExceptionUtils.describe; + import com.github.kagkarlsson.scheduler.logging.ConfigurableLogger; import com.github.kagkarlsson.scheduler.stats.StatsRegistry; import com.github.kagkarlsson.scheduler.task.CompletionHandler; @@ -129,9 +131,10 @@ private void complete( statsRegistry.register(StatsRegistry.SchedulerStatsEvent.COMPLETIONHANDLER_ERROR); statsRegistry.register(StatsRegistry.SchedulerStatsEvent.UNEXPECTED_ERROR); LOG.error( - "Failed while completing execution {}. Execution will likely remain scheduled and locked/picked. " + "Failed while completing execution {}, because {}. Execution will likely remain scheduled and locked/picked. " + "The execution should be detected as dead after a while, and handled according to the tasks DeadExecutionHandler.", execution, + describe(e), e); } } @@ -142,9 +145,8 @@ private void failure( Throwable cause, Instant executionStarted, String errorMessagePrefix) { - String logMessage = - errorMessagePrefix + " during execution of task with name '{}'. Treating as failure."; - failureLogger.log(logMessage, cause, task.getName()); + String logMessage = "{} {} during execution of task with name '{}'. Treating as failure."; + failureLogger.log(logMessage, cause, errorMessagePrefix, describe(cause), task.getName()); ExecutionComplete completeEvent = ExecutionComplete.failure(execution, executionStarted, clock.now(), cause); @@ -158,9 +160,10 @@ private void failure( statsRegistry.register(StatsRegistry.SchedulerStatsEvent.FAILUREHANDLER_ERROR); statsRegistry.register(StatsRegistry.SchedulerStatsEvent.UNEXPECTED_ERROR); LOG.error( - "Failed while completing execution {}. Execution will likely remain scheduled and locked/picked. " + "Failed while completing execution {}, because {}. Execution will likely remain scheduled and locked/picked. " + "The execution should be detected as dead after a while, and handled according to the tasks DeadExecutionHandler.", execution, + describe(cause), e); } } diff --git a/db-scheduler/src/test/java/com/github/kagkarlsson/scheduler/ExceptionUtilsTest.java b/db-scheduler/src/test/java/com/github/kagkarlsson/scheduler/ExceptionUtilsTest.java new file mode 100644 index 00000000..6f638ea4 --- /dev/null +++ b/db-scheduler/src/test/java/com/github/kagkarlsson/scheduler/ExceptionUtilsTest.java @@ -0,0 +1,28 @@ +package com.github.kagkarlsson.scheduler; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.is; +import static org.hamcrest.Matchers.nullValue; + +import java.io.IOException; +import org.junit.jupiter.api.Test; + +class ExceptionUtilsTest { + + @Test + void exceptionWithNoMessageDescribedAsItsClassSimpleName() { + assertThat( + ExceptionUtils.describe(new IllegalArgumentException()), is("IllegalArgumentException")); + } + + @Test + void exceptionDescribedAsClassSimpleNameAndMessage() { + assertThat( + ExceptionUtils.describe(new IOException("timed out")), is("IOException: 'timed out'")); + } + + @Test + void describingNullIsNull() { + assertThat(ExceptionUtils.describe(null), is(nullValue())); + } +}