From 67275eb2f512882e235738e250c98bddcf3d2a86 Mon Sep 17 00:00:00 2001 From: Marcus van Elst Date: Thu, 23 Apr 2026 17:58:30 +0200 Subject: [PATCH] Fix #17: Fehler und Warnungen nicht mehr als INFO loggen MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Verarbeitungsfehler (PreCheckFailed, AiFunctionalFailure) und Retry-Entscheidungen (FAILED_RETRYABLE, FAILED_FINAL) werden nun auf WARN-Level geloggt. EmptyList- und IncompleteConfiguration-Ergebnisse des Modellabrufs sowie fehlende Quelldateien im Mini-Lauf ebenfalls. Tests angepasst: Assertions prüfen jetzt das korrekte WARN-Level. Co-Authored-By: Claude Sonnet 4.6 --- .../in/gui/GuiModelCatalogCoordinator.java | 4 +- .../in/gui/batchrun/GuiBatchRunTab.java | 2 +- .../DocumentProcessingCoordinator.java | 8 ++-- .../DefaultBatchRunProcessingUseCase.java | 4 +- .../DocumentProcessingCoordinatorTest.java | 44 ++++++++++--------- .../BatchRunProcessingUseCaseTest.java | 16 ++++--- 6 files changed, 43 insertions(+), 35 deletions(-) diff --git a/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/GuiModelCatalogCoordinator.java b/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/GuiModelCatalogCoordinator.java index 01b4243..d50ef1d 100644 --- a/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/GuiModelCatalogCoordinator.java +++ b/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/GuiModelCatalogCoordinator.java @@ -194,14 +194,14 @@ public final class GuiModelCatalogCoordinator { String message = "Provider " + displayName + " liefert aktuell keine Modelle. Manuelle Eingabe aktiv."; pendingMessages.add(GuiMessageEntry.of(GuiMessageSeverity.HINT, message, "Modellabruf")); - LOG.info("GUI-Modellabruf: {} (Provider: {})", message, family.getIdentifier()); + LOG.warn("GUI-Modellabruf: {} (Provider: {})", message, family.getIdentifier()); } case ModelCatalogResult.IncompleteConfiguration incomplete -> { container.applyManualFallback(GuiModelSource.LIST_UNAVAILABLE_MANUAL_INPUT); String message = "Modellliste nicht abrufbar: " + incomplete.missingReason() + ". Manuelle Eingabe aktiv."; pendingMessages.add(GuiMessageEntry.of(GuiMessageSeverity.WARNING, message, "Modellabruf")); - LOG.info("GUI-Modellabruf: {} (Provider: {})", message, family.getIdentifier()); + LOG.warn("GUI-Modellabruf: {} (Provider: {})", message, family.getIdentifier()); } case ModelCatalogResult.TechnicalFailure failure -> { container.applyManualFallback(GuiModelSource.LIST_FAILED_MANUAL_INPUT); diff --git a/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/batchrun/GuiBatchRunTab.java b/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/batchrun/GuiBatchRunTab.java index 4acd89a..474a6ac 100644 --- a/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/batchrun/GuiBatchRunTab.java +++ b/pdf-umbenenner-adapter-in-gui/src/main/java/de/gecheckt/pdf/umbenenner/adapter/in/gui/batchrun/GuiBatchRunTab.java @@ -1017,7 +1017,7 @@ public final class GuiBatchRunTab { upsertResultRowByFingerprint(missingRow); appendMessage(message); failedCount++; - LOG.info("GUI-Mini-Lauf: Quelldatei fehlt für Auswahl '{}' – Status " + LOG.warn("GUI-Mini-Lauf: Quelldatei fehlt für Auswahl '{}' – Status " + "permanent fehlgeschlagen.", originalName); } } diff --git a/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinator.java b/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinator.java index 2104b0b..1d708f2 100644 --- a/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinator.java +++ b/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinator.java @@ -688,12 +688,12 @@ public class DocumentProcessingCoordinator { }); if (!retryable) { - logger.info("Retry decision for '{}' (fingerprint: {}): FAILED_FINAL — " + logger.warn("Retry decision for '{}' (fingerprint: {}): FAILED_FINAL — " + "transient error limit reached ({}/{} attempts). No further retry.", candidate.uniqueIdentifier(), fingerprint.sha256Hex(), updatedCounters.transientErrorCount(), maxRetriesTransient); } else { - logger.info("Retry decision for '{}' (fingerprint: {}): FAILED_RETRYABLE — " + logger.warn("Retry decision for '{}' (fingerprint: {}): FAILED_RETRYABLE — " + "transient error, will retry in later run ({}/{} attempts).", candidate.uniqueIdentifier(), fingerprint.sha256Hex(), updatedCounters.transientErrorCount(), maxRetriesTransient); @@ -1060,14 +1060,14 @@ public class DocumentProcessingCoordinator { }); if (outcome.overallStatus() == ProcessingStatus.FAILED_RETRYABLE) { - logger.info("Retry decision for '{}' (fingerprint: {}): FAILED_RETRYABLE — " + logger.warn("Retry decision for '{}' (fingerprint: {}): FAILED_RETRYABLE — " + "will retry in later scheduler run. " + "ContentErrors={}, TransientErrors={}.", candidate.uniqueIdentifier(), fingerprint.sha256Hex(), outcome.counters().contentErrorCount(), outcome.counters().transientErrorCount()); } else if (outcome.overallStatus() == ProcessingStatus.FAILED_FINAL) { - logger.info("Retry decision for '{}' (fingerprint: {}): FAILED_FINAL — " + logger.warn("Retry decision for '{}' (fingerprint: {}): FAILED_FINAL — " + "permanently failed, no further retry. " + "ContentErrors={}, TransientErrors={}.", candidate.uniqueIdentifier(), fingerprint.sha256Hex(), diff --git a/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/usecase/DefaultBatchRunProcessingUseCase.java b/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/usecase/DefaultBatchRunProcessingUseCase.java index b757318..7837123 100644 --- a/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/usecase/DefaultBatchRunProcessingUseCase.java +++ b/pdf-umbenenner-application/src/main/java/de/gecheckt/pdf/umbenenner/application/usecase/DefaultBatchRunProcessingUseCase.java @@ -554,7 +554,7 @@ public class DefaultBatchRunProcessingUseCase implements BatchRunProcessingUseCa private void logProcessingOutcome(SourceDocumentCandidate candidate, DocumentProcessingOutcome outcome) { switch (outcome) { case de.gecheckt.pdf.umbenenner.domain.model.PreCheckFailed failed -> - logger.info("Pre-checks failed for '{}': {} (deterministic content error).", + logger.warn("Pre-checks failed for '{}': {} (deterministic content error).", candidate.uniqueIdentifier(), failed.failureReasonDescription()); case de.gecheckt.pdf.umbenenner.domain.model.TechnicalDocumentError technicalError -> logger.warn("Processing failed for '{}': {} (transient technical error – retryable).", @@ -568,7 +568,7 @@ public class DefaultBatchRunProcessingUseCase implements BatchRunProcessingUseCa logger.warn("AI invocation failed for '{}': {} (transient technical error – retryable).", candidate.uniqueIdentifier(), aiTechnical.errorMessage()); case de.gecheckt.pdf.umbenenner.domain.model.AiFunctionalFailure aiFunctional -> - logger.info("AI naming failed for '{}': {} (deterministic content error).", + logger.warn("AI naming failed for '{}': {} (deterministic content error).", candidate.uniqueIdentifier(), aiFunctional.errorMessage()); default -> { /* other outcomes are handled elsewhere */ } } diff --git a/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinatorTest.java b/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinatorTest.java index fc64661..34b4017 100644 --- a/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinatorTest.java +++ b/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/service/DocumentProcessingCoordinatorTest.java @@ -770,8 +770,8 @@ class DocumentProcessingCoordinatorTest { coordinatorWithCapturingLogger.process(candidate, fingerprint, outcome, context, attemptStart); - assertTrue(capturingLogger.infoCallCount > 0, - "Nach erfolgreichem Verarbeiten eines neuen Dokuments muss eine Info geloggt werden"); + assertTrue(capturingLogger.warnCallCount > 0, + "Nach Verarbeiten eines neuen Dokuments mit PreCheckPassed muss eine Warnung geloggt werden"); } @Test @@ -1126,12 +1126,12 @@ class DocumentProcessingCoordinatorTest { coordinatorWithCapturing.processDeferredOutcome(candidate, fingerprint, context, attemptStart, c -> null); - assertTrue(capturingLogger.anyInfoContains("FAILED_RETRYABLE"), + assertTrue(capturingLogger.anyWarnContains("FAILED_RETRYABLE"), "Retry decision log for a retryable transient copy error must contain FAILED_RETRYABLE. " - + "Captured info messages: " + capturingLogger.infoMessages); - assertTrue(capturingLogger.anyInfoContains("will retry in later run"), + + "Captured warn messages: " + capturingLogger.warnMessages); + assertTrue(capturingLogger.anyWarnContains("will retry in later run"), "Retry decision log for a retryable transient error must contain 'will retry in later run'. " - + "Captured info messages: " + capturingLogger.infoMessages); + + "Captured warn messages: " + capturingLogger.warnMessages); } @Test @@ -1153,12 +1153,12 @@ class DocumentProcessingCoordinatorTest { coordinatorWithCapturing.processDeferredOutcome(candidate, fingerprint, context, attemptStart, c -> null); - assertTrue(capturingLogger.anyInfoContains("FAILED_FINAL"), + assertTrue(capturingLogger.anyWarnContains("FAILED_FINAL"), "Retry decision log for a finalising transient copy error must contain FAILED_FINAL. " - + "Captured info messages: " + capturingLogger.infoMessages); - assertTrue(capturingLogger.anyInfoContains("transient error limit reached"), + + "Captured warn messages: " + capturingLogger.warnMessages); + assertTrue(capturingLogger.anyWarnContains("transient error limit reached"), "Retry decision log for a finalising transient error must contain 'transient error limit reached'. " - + "Captured info messages: " + capturingLogger.infoMessages); + + "Captured warn messages: " + capturingLogger.warnMessages); } @Test @@ -1602,12 +1602,12 @@ class DocumentProcessingCoordinatorTest { new PreCheckFailed(candidate, PreCheckFailureReason.NO_USABLE_TEXT), context, attemptStart); - assertTrue(capturingLogger.anyInfoContains(FINGERPRINT_HEX), + assertTrue(capturingLogger.anyWarnContains(FINGERPRINT_HEX), "Retry decision log must contain the document fingerprint. " - + "Captured info messages: " + capturingLogger.infoMessages); - assertTrue(capturingLogger.anyInfoContains("FAILED_RETRYABLE"), + + "Captured warn messages: " + capturingLogger.warnMessages); + assertTrue(capturingLogger.anyWarnContains("FAILED_RETRYABLE"), "Retry decision log must contain the FAILED_RETRYABLE classification. " - + "Captured info messages: " + capturingLogger.infoMessages); + + "Captured warn messages: " + capturingLogger.warnMessages); } @Test @@ -1627,16 +1627,16 @@ class DocumentProcessingCoordinatorTest { new PreCheckFailed(candidate, PreCheckFailureReason.PAGE_LIMIT_EXCEEDED), context, attemptStart); - assertTrue(capturingLogger.anyInfoContains(FINGERPRINT_HEX), + assertTrue(capturingLogger.anyWarnContains(FINGERPRINT_HEX), "Finalising retry decision log must contain the document fingerprint. " - + "Captured info messages: " + capturingLogger.infoMessages); - assertTrue(capturingLogger.anyInfoContains("FAILED_FINAL"), + + "Captured warn messages: " + capturingLogger.warnMessages); + assertTrue(capturingLogger.anyWarnContains("FAILED_FINAL"), "Finalising retry decision log must contain the FAILED_FINAL classification. " - + "Captured info messages: " + capturingLogger.infoMessages); - assertTrue(capturingLogger.anyInfoContains("permanently failed"), + + "Captured warn messages: " + capturingLogger.warnMessages); + assertTrue(capturingLogger.anyWarnContains("permanently failed"), "Finalising retry decision log must contain 'permanently failed' to distinguish " + "the FAILED_FINAL branch from the generic status log. " - + "Captured info messages: " + capturingLogger.infoMessages); + + "Captured warn messages: " + capturingLogger.warnMessages); } // ------------------------------------------------------------------------- @@ -1879,6 +1879,10 @@ class DocumentProcessingCoordinatorTest { return infoMessages.stream().anyMatch(m -> m.contains(text)); } + boolean anyWarnContains(String text) { + return warnMessages.stream().anyMatch(m -> m.contains(text)); + } + boolean anyErrorContains(String text) { return errorMessages.stream().anyMatch(m -> m.contains(text)); } diff --git a/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/usecase/BatchRunProcessingUseCaseTest.java b/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/usecase/BatchRunProcessingUseCaseTest.java index 4aae1d2..5521bde 100644 --- a/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/usecase/BatchRunProcessingUseCaseTest.java +++ b/pdf-umbenenner-application/src/test/java/de/gecheckt/pdf/umbenenner/application/usecase/BatchRunProcessingUseCaseTest.java @@ -672,10 +672,11 @@ class BatchRunProcessingUseCaseTest { } @Test - void execute_extractionContentError_logsDebugAndPreCheckFailedInfo() throws Exception { - // Prüft, dass bei PdfExtractionContentError debug (logExtractionResult) und info (logProcessingOutcome) geloggt wird. + void execute_extractionContentError_logsDebugAndPreCheckFailedWarn() throws Exception { + // Prüft, dass bei PdfExtractionContentError debug (logExtractionResult) und warn (logProcessingOutcome) geloggt wird. // Erwartete debug()-Aufrufe: 4 (lock acquired + fingerprint + logExtractionResult (content) + lock released) - // Erwartete info()-Aufrufe: 6 (Batch initiiert + gestartet + Kandidaten gefunden + erkannte Quelldatei + PreCheckFailed + abgeschlossen) + // Erwartete info()-Aufrufe: 5 (Batch initiiert + gestartet + Kandidaten gefunden + erkannte Quelldatei + abgeschlossen) + // Erwartete warn()-Aufrufe: >= 1 (PreCheckFailed) CapturingProcessingLogger capturingLogger = new CapturingProcessingLogger(); RuntimeConfiguration config = buildConfig(tempDir); @@ -695,10 +696,13 @@ class BatchRunProcessingUseCaseTest { assertTrue(capturingLogger.debugCallCount >= 4, "logExtractionResult muss bei PdfExtractionContentError debug() aufrufen (erwartet >= 4, war: " + capturingLogger.debugCallCount + ")"); - // Ohne logProcessingOutcome (PreCheckFailed) wären es 5 info()-Aufrufe; mit >= 6 - assertTrue(capturingLogger.infoCallCount >= 6, - "logProcessingOutcome muss bei PreCheckFailed info() aufrufen (erwartet >= 6, war: " + // PreCheckFailed wird als WARN geloggt; ohne diesen Aufruf wären es 5 info()-Aufrufe + assertTrue(capturingLogger.infoCallCount >= 5, + "Batch-Ablauf muss bei PdfExtractionContentError mind. 5 info()-Aufrufe erzeugen (erwartet >= 5, war: " + capturingLogger.infoCallCount + ")"); + assertTrue(capturingLogger.warnCallCount >= 1, + "logProcessingOutcome muss bei PreCheckFailed warn() aufrufen (erwartet >= 1, war: " + + capturingLogger.warnCallCount + ")"); } @Test