Improve logging

itsallcode · Apr 14, 2024 · 44ea65c · 44ea65c
1 parent c30e690
commit 44ea65c
Show file tree

Hide file tree

Showing 6 changed files with 40 additions and 32 deletions.
diff --git a/jfxui/src/main/java/org/itsallcode/whiterabbit/jfxui/ui/MonthlyProjectReportViewer.java b/jfxui/src/main/java/org/itsallcode/whiterabbit/jfxui/ui/MonthlyProjectReportViewer.java
@@ -6,6 +6,8 @@
 import java.time.YearMonth;
 import java.util.List;
 
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.itsallcode.whiterabbit.api.model.ProjectReport;
 import org.itsallcode.whiterabbit.api.model.ProjectReportActivity;
 import org.itsallcode.whiterabbit.jfxui.table.converter.DurationStringConverter;
@@ -25,6 +27,7 @@
 
 public class MonthlyProjectReportViewer
 {
+    private static final Logger LOG = LogManager.getLogger(MonthlyProjectReportViewer.class);
 
     private final ReportWindow reportWindow;
     private final UiStateService uiState;
@@ -45,23 +48,17 @@ public void show()
         final TableView<ReportRow> treeTable = createTreeTable();
         updateTable(treeTable);
         final Node previousMonthButton = UiWidget.button("prev-month-button", "< Previous Month",
-                e -> gotoPreviousMonth(treeTable));
+                e -> gotoMonth(treeTable, -1));
         final Node nextMonthButton = UiWidget.button("next-month-button", "Next Month >",
-                e -> gotoNextMonth(treeTable));
+                e -> gotoMonth(treeTable, +1));
         reportWindow.show(treeTable, previousMonthButton, nextMonthButton);
         uiState.register(treeTable);
     }
 
-    private void gotoPreviousMonth(final TableView<ReportRow> treeTable)
+    private void gotoMonth(final TableView<ReportRow> treeTable, final int count)
     {
-        yearMonth = yearMonth.minusMonths(1);
-        updateTable(treeTable);
-        reportWindow.updateTitle(getWindowTitle());
-    }
-
-    private void gotoNextMonth(final TableView<ReportRow> treeTable)
-    {
-        yearMonth = yearMonth.plusMonths(1);
+        yearMonth = yearMonth.plusMonths(count);
+        LOG.debug("Go {} months to {}", count, yearMonth);
         updateTable(treeTable);
         reportWindow.updateTitle(getWindowTitle());
     }

diff --git a/jfxui/src/main/java/org/itsallcode/whiterabbit/jfxui/ui/widget/ReportWindow.java b/jfxui/src/main/java/org/itsallcode/whiterabbit/jfxui/ui/widget/ReportWindow.java
@@ -41,6 +41,7 @@ public ReportWindow(final Stage primaryStage, final UiStateService uiState, fina
     public void show(final Node reportView, final Node... toolBarItems)
     {
         stage = createStage(reportView, toolBarItems);
+        LOG.debug("Show report window");
         stage.show();
     }
 
@@ -89,6 +90,7 @@ public void updateTitle(final String title)
 
     private void closeReportWindow()
     {
+        LOG.debug("Closing window '{}'", stage.getTitle());
         this.stage.close();
     }
 }
diff --git a/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/JavaFxAppUiTestBase.java b/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/JavaFxAppUiTestBase.java
@@ -60,7 +60,7 @@ abstract class JavaFxAppUiTestBase
     private ApplicationHelper applicationHelper;
     private TimeUtil timeUtil;
 
-    protected void setRobot(FxRobot robot)
+    protected void setRobot(final FxRobot robot)
     {
         applicationHelper = ApplicationHelper.create(robot);
     }
@@ -80,12 +80,12 @@ protected void doStart(final Stage stage)
         doStart(stage, null);
     }
 
-    protected void setInitialTime(Instant initialTime)
+    protected void setInitialTime(final Instant initialTime)
     {
         this.initialTime = initialTime;
     }
 
-    public void setCommandLineArgs(List<String> commandLineArgs)
+    public void setCommandLineArgs(final List<String> commandLineArgs)
     {
         this.commandLineArgs = commandLineArgs;
     }
@@ -117,7 +117,7 @@ protected void doStop()
         LOG.info("Application shutdown done");
     }
 
-    private void prepareConfiguration(final ProjectConfig projectConfig, WorkingDirProvider testDirProvider)
+    private void prepareConfiguration(final ProjectConfig projectConfig, final WorkingDirProvider testDirProvider)
     {
         this.dataDir = this.tempDir.resolve("data-dir");
         String configFileContent = "data = " + this.dataDir.toString().replace('\\', '/') + "\n";
@@ -200,12 +200,12 @@ private static class TestDirProvider implements WorkingDirProvider
     {
         private final Path tempDir;
 
-        private TestDirProvider(Path tempDir)
+        private TestDirProvider(final Path tempDir)
         {
             this.tempDir = Objects.requireNonNull(tempDir, "tempDir");
         }
 
-        public static TestDirProvider create(Path tempDir)
+        public static TestDirProvider create(final Path tempDir)
         {
             final TestDirProvider dirProvider = new TestDirProvider(tempDir);
             try
@@ -215,7 +215,7 @@ public static TestDirProvider create(Path tempDir)
             }
             catch (final IOException e)
             {
-                throw new UncheckedIOException("Error creating temp directories", e);
+                throw new UncheckedIOException("Error creating temp directories at " + tempDir, e);
             }
             return dirProvider;
         }

diff --git a/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/testutil/TestUtil.java b/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/testutil/TestUtil.java
@@ -1,6 +1,7 @@
 package org.itsallcode.whiterabbit.jfxui.testutil;
 
 import java.time.Duration;
+import java.time.Instant;
 
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
@@ -38,22 +39,28 @@ private static void sleep(final Duration duration)
 
     public static void retryAssertion(final Duration duration, final Runnable assertion)
     {
-        final long start = System.currentTimeMillis();
+        final Instant start = Instant.now();
+        int tries = 0;
         while (true)
         {
             try
             {
+                tries++;
                 assertion.run();
                 return;
             }
             catch (final AssertionError e)
             {
-                LOG.warn("Assertion failed: {}", e.getMessage(), e);
-                if (System.currentTimeMillis() - start > duration.toMillis())
+                final Duration currentDuration = Duration.between(start, Instant.now());
+                final String message = "Assertion failed after " + currentDuration + " / " + tries + " tries: "
+                        + e.getMessage();
+                final Duration remaining = currentDuration.minus(duration);
+                if (remaining.isPositive())
                 {
-                    throw e;
+                    throw new AssertionError(message, e);
                 }
-                sleepShort();
+                LOG.warn(message);
+                sleepLong();
             }
         }
     }

diff --git a/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/testutil/model/JavaFxTable.java b/jfxui/src/uiTest/java/org/itsallcode/whiterabbit/jfxui/testutil/model/JavaFxTable.java
@@ -16,7 +16,9 @@
 import org.testfx.assertions.api.Assertions;
 
 import javafx.css.PseudoClass;
-import javafx.scene.control.*;
+import javafx.scene.control.IndexedCell;
+import javafx.scene.control.TableCell;
+import javafx.scene.control.TableView;
 import javafx.scene.control.skin.VirtualFlow;
 
 public class JavaFxTable<T>
@@ -112,7 +114,7 @@ public void assertContent(final TableRowExpectedContent expectedRowContent)
 
         public TableCell<?, ?> cell(final String columnId)
         {
-            LOG.debug("Getting row {} / column {}", rowIndex, columnId);
+            LOG.trace("Getting row {} / column {}", rowIndex, columnId);
             final IndexedCell<T> row = tableRow();
             return row.getChildrenUnmodifiable().stream()
                     .filter(cell -> cell.getId().equals(columnId))
@@ -129,7 +131,7 @@ public IndexedCell<T> tableRow()
                     .findFirst().orElseThrow();
             assertThat(virtualFlow.getCellCount()).as("row count of " + virtualFlow).isGreaterThan(rowIndex);
             final IndexedCell<T> row = JavaFxUtil.runOnFxApplicationThread(() -> virtualFlow.getCell(rowIndex));
-            LOG.debug("Got row #{} of {}: {}", rowIndex, virtualFlow, row);
+            LOG.trace("Got row #{} of {}: {}", rowIndex, virtualFlow, row);
             return row;
         }
 

diff --git a/...Test/java/org/itsallcode/whiterabbit/jfxui/testutil/model/MonthlyProjectReportWindow.java b/...Test/java/org/itsallcode/whiterabbit/jfxui/testutil/model/MonthlyProjectReportWindow.java
@@ -36,6 +36,12 @@ public void closeViaCloseButton()
         Assertions.assertThat(window).isNotShowing();
     }
 
+    public void closeViaEscKey()
+    {
+        robot.type(KeyCode.ESCAPE);
+        Assertions.assertThat(window).isNotShowing();
+    }
+
     public void gotoPreviousMonth()
     {
         robot.clickOn("#prev-month-button");
@@ -46,12 +52,6 @@ public void gotoNextMonth()
         robot.clickOn("#next-month-button");
     }
 
-    public void closeViaEscKey()
-    {
-        robot.type(KeyCode.ESCAPE);
-        Assertions.assertThat(window).isNotShowing();
-    }
-
     public MonthlyProjectReportWindow assertWindowTitle(final String expectedTitle)
     {
         final String title = ((Stage) window).getTitle();