From ca91749a04262e6ac026b7163781023ee78b86d2 Mon Sep 17 00:00:00 2001 From: Marcus van Elst Date: Thu, 9 Apr 2026 11:55:17 +0200 Subject: [PATCH] =?UTF-8?q?PIT-L=C3=BCcken=20in=20bootstrap=20gezielt=20ge?= =?UTF-8?q?schlossen?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../adapter/Log4jProcessingLogger.java | 11 +- .../BootstrapRunnerEdgeCasesTest.java | 147 ++++++++++++++++++ .../adapter/Log4jProcessingLoggerTest.java | 17 ++ 3 files changed, 167 insertions(+), 8 deletions(-) diff --git a/pdf-umbenenner-bootstrap/src/main/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLogger.java b/pdf-umbenenner-bootstrap/src/main/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLogger.java index 66e71fb..3f29b30 100644 --- a/pdf-umbenenner-bootstrap/src/main/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLogger.java +++ b/pdf-umbenenner-bootstrap/src/main/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLogger.java @@ -83,14 +83,9 @@ public class Log4jProcessingLogger implements ProcessingLogger { @Override public void error(String message, Object... args) { - // If the last argument is a Throwable, extract it and pass separately - if (args.length > 0 && args[args.length - 1] instanceof Throwable throwable) { - Object[] messageArgs = new Object[args.length - 1]; - System.arraycopy(args, 0, messageArgs, 0, args.length - 1); - log4jLogger.error(message, throwable, messageArgs); - } else { - log4jLogger.error(message, args); - } + // Log4j2 detects a trailing Throwable in the params array automatically: + // it uses it as the log cause and formats only the preceding arguments. + log4jLogger.error(message, args); } } diff --git a/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/BootstrapRunnerEdgeCasesTest.java b/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/BootstrapRunnerEdgeCasesTest.java index f3a7257..f130a77 100644 --- a/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/BootstrapRunnerEdgeCasesTest.java +++ b/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/BootstrapRunnerEdgeCasesTest.java @@ -8,8 +8,18 @@ import static org.junit.jupiter.api.Assertions.assertTrue; import java.nio.file.Files; import java.nio.file.Path; +import java.util.ArrayList; +import java.util.List; +import java.util.UUID; import java.util.concurrent.atomic.AtomicReference; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.Property; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.io.TempDir; @@ -339,6 +349,143 @@ class BootstrapRunnerEdgeCasesTest { "logAiSensitive=true must resolve to LOG_SENSITIVE_CONTENT"); } + // ========================================================================= + // mapOutcomeToExitCode: log level semantics + // ========================================================================= + + /** + * LOCK_UNAVAILABLE is an expected operational situation (another instance is already running) + * and must be logged at WARN level, not ERROR. Verifies that the conditional branch + * for {@link BatchRunOutcome#LOCK_UNAVAILABLE} is distinct from the generic failure branch. + */ + @Test + void mapOutcomeToExitCode_lockUnavailableLogsAtWarnLevel() throws Exception { + ConfigurationPort mockConfigPort = new MockConfigurationPort(tempDir, true); + List capturedEvents = new ArrayList<>(); + String appenderName = "TestCapture-LockWarn-" + UUID.randomUUID(); + + LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + Configuration cfg = ctx.getConfiguration(); + AbstractAppender captureAppender = new AbstractAppender( + appenderName, null, null, false, Property.EMPTY_ARRAY) { + @Override + public void append(LogEvent event) { + capturedEvents.add(event.toImmutable()); + } + }; + captureAppender.start(); + cfg.addAppender(captureAppender); + cfg.getRootLogger().addAppender(captureAppender, Level.ALL, null); + ctx.updateLoggers(); + + BootstrapRunner runner = new BootstrapRunner( + () -> mockConfigPort, + lockFile -> new MockRunLockPort(), + StartConfigurationValidator::new, + jdbcUrl -> new MockSchemaInitializationPort(), + (config, lock) -> context -> BatchRunOutcome.LOCK_UNAVAILABLE, + SchedulerBatchCommand::new + ); + try { + runner.run(); + } finally { + cfg.getRootLogger().removeAppender(appenderName); + ctx.updateLoggers(); + captureAppender.stop(); + } + + assertTrue( + capturedEvents.stream().anyMatch(e -> + e.getLevel() == Level.WARN + && e.getMessage().getFormattedMessage().contains("another instance")), + "LOCK_UNAVAILABLE must produce a WARN-level log mentioning another instance is running"); + assertTrue( + capturedEvents.stream().noneMatch(e -> + e.getLevel() == Level.ERROR + && e.getMessage().getFormattedMessage().contains("another instance")), + "LOCK_UNAVAILABLE must not produce an ERROR-level log"); + } + + /** + * A true batch FAILURE (infrastructure error) must be logged at ERROR level, not WARN. + * Verifies the else branch of {@link BatchRunOutcome#FAILURE} uses the error log path. + */ + @Test + void mapOutcomeToExitCode_failureLogsAtErrorLevel() throws Exception { + ConfigurationPort mockConfigPort = new MockConfigurationPort(tempDir, true); + List capturedEvents = new ArrayList<>(); + String appenderName = "TestCapture-Failure-" + UUID.randomUUID(); + + LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + Configuration cfg = ctx.getConfiguration(); + AbstractAppender captureAppender = new AbstractAppender( + appenderName, null, null, false, Property.EMPTY_ARRAY) { + @Override + public void append(LogEvent event) { + capturedEvents.add(event.toImmutable()); + } + }; + captureAppender.start(); + cfg.addAppender(captureAppender); + cfg.getRootLogger().addAppender(captureAppender, Level.ALL, null); + ctx.updateLoggers(); + + BootstrapRunner runner = new BootstrapRunner( + () -> mockConfigPort, + lockFile -> new MockRunLockPort(), + StartConfigurationValidator::new, + jdbcUrl -> new MockSchemaInitializationPort(), + (config, lock) -> context -> BatchRunOutcome.FAILURE, + SchedulerBatchCommand::new + ); + try { + runner.run(); + } finally { + cfg.getRootLogger().removeAppender(appenderName); + ctx.updateLoggers(); + captureAppender.stop(); + } + + assertTrue( + capturedEvents.stream().anyMatch(e -> + e.getLevel() == Level.ERROR + && e.getMessage().getFormattedMessage().contains("failed")), + "Batch FAILURE must produce an ERROR-level log mentioning the run failed"); + } + + // ========================================================================= + // executeWithStartConfiguration: run context lifecycle + // ========================================================================= + + /** + * The end instant on the {@link BatchRunContext} must be set after the batch command returns. + * A missing setEndInstant call would leave the context without a completion timestamp, + * breaking run completion logging. + */ + @Test + void executeWithStartConfiguration_setsEndInstantOnBatchRunContext() throws Exception { + AtomicReference capturedContext = new AtomicReference<>(); + ConfigurationPort mockConfigPort = new MockConfigurationPort(tempDir, true); + + BootstrapRunner runner = new BootstrapRunner( + () -> mockConfigPort, + lockFile -> new MockRunLockPort(), + StartConfigurationValidator::new, + jdbcUrl -> new MockSchemaInitializationPort(), + (config, lock) -> context -> { + capturedContext.set(context); + return BatchRunOutcome.SUCCESS; + }, + SchedulerBatchCommand::new + ); + + runner.run(); + + assertNotNull(capturedContext.get(), "BatchRunContext should have been passed to the use case"); + assertTrue(capturedContext.get().isCompleted(), + "End instant must be set on BatchRunContext after the batch command completes"); + } + // ------------------------------------------------------------------------- // Helpers // ------------------------------------------------------------------------- diff --git a/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLoggerTest.java b/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLoggerTest.java index 099e559..fff2805 100644 --- a/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLoggerTest.java +++ b/pdf-umbenenner-bootstrap/src/test/java/de/gecheckt/pdf/umbenenner/bootstrap/adapter/Log4jProcessingLoggerTest.java @@ -175,6 +175,23 @@ class Log4jProcessingLoggerTest { }, "error() should handle Throwable as non-last argument as format parameter"); } + /** + * Verifies that format arguments before the trailing Throwable are preserved in the + * formatted log message. Without a correct arraycopy, the message args would be empty + * (all nulls) and the substituted values would not appear in the log output. + */ + @Test + void error_withFormatArgsAndThrowable_preservesFormatArgsInMessage() { + String expectedArg = "EXPECTED_FORMAT_ARG_7c4a3b1e"; + logCapture = new TestLogCapture(); + logCapture.startCapture(); + logger.error("Processing failed for {}", expectedArg, new RuntimeException("test failure")); + logCapture.stopCapture(); + + assertTrue(logCapture.containsMessage(expectedArg), + "Format args before the trailing Throwable must appear in the formatted log message"); + } + @Test void implementsProcessingLoggerInterface() { // Verify that Log4jProcessingLogger correctly implements ProcessingLogger