add log level shifting

fixes #3736

Author: vladak

opengrok-indexer/src/main/java/org/opengrok/indexer/history/BoundaryChangesets.java

@@ -102,14 +102,12 @@ public synchronized List<String> getBoundaryChangesetIDs(String sinceRevision) t
         reset();
 
         Level logLevel = Level.FINE;
-        if (RuntimeEnvironment.getInstance().isPrintProgress()) {
-            logLevel = Level.INFO;
-        }
 
         LOGGER.log(logLevel, "getting boundary changesets for {0}", repository);
         Statistics stat = new Statistics();
 
-        try (Progress progress = new Progress(LOGGER, String.format("changesets visited of %s", this.repository))) {
+        try (Progress progress = new Progress(LOGGER, String.format("changesets visited of %s", this.repository),
+                logLevel)) {
             repository.accept(sinceRevision, this::visit, progress);
         }
 

opengrok-indexer/src/main/java/org/opengrok/indexer/util/Progress.java

@@ -23,10 +23,15 @@
  */
 package org.opengrok.indexer.util;
 
+import org.jetbrains.annotations.VisibleForTesting;
 import org.opengrok.indexer.configuration.RuntimeEnvironment;
 
+import java.util.Arrays;
+import java.util.Comparator;
 import java.util.HashMap;
+import java.util.List;
 import java.util.Map;
+import java.util.TreeMap;
 import java.util.concurrent.atomic.AtomicLong;
 import java.util.logging.Level;
 import java.util.logging.Logger;
@@ -35,26 +40,37 @@
  * Progress reporting via logging. The idea is that for anything that has a set of items
  * to go through, it will ping an instance of this class for each item completed.
  * This class will then log based on the number of pings. The bigger the progress,
- * the higher log level ({@link Level} value) will be used.
+ * the higher log level ({@link Level} value) will be used. The default base level is {@code Level.INFO}.
  */
 public class Progress implements AutoCloseable {
     private final Logger logger;
     private final Long totalCount;
     private final String suffix;
 
     private final AtomicLong currentCount = new AtomicLong();
-    private final Map<Level, Integer> levelCount;
+    private final Map<Level, Integer> levelCountMap = new TreeMap<>(Comparator.comparingInt(Level::intValue).reversed());
     private Thread loggerThread = null;
     private volatile boolean run;
 
+    private final Level baseLogLevel;
+
     private final Object sync = new Object();
 
     /**
      * @param logger logger instance
      * @param suffix string suffix to identify the operation
      */
     public Progress(Logger logger, String suffix) {
-        this(logger, suffix, -1);
+        this(logger, suffix, -1, Level.INFO);
+    }
+
+    /**
+     * @param logger logger instance
+     * @param suffix string suffix to identify the operation
+     * @param logLevel base log level
+     */
+    public Progress(Logger logger, String suffix, Level logLevel) {
+        this(logger, suffix, -1, logLevel);
     }
 
     /**
@@ -63,22 +79,44 @@ public Progress(Logger logger, String suffix) {
      * @param totalCount total count
      */
     public Progress(Logger logger, String suffix, long totalCount) {
+        this(logger, suffix, totalCount, Level.INFO);
+    }
+
+    /**
+     * @param logger logger instance
+     * @param suffix string suffix to identify the operation
+     * @param totalCount total count
+     * @param logLevel base log level
+     */
+    public Progress(Logger logger, String suffix, long totalCount, Level logLevel) {
         this.logger = logger;
         this.suffix = suffix;
+        this.baseLogLevel = logLevel;
 
         if (totalCount < 0) {
             this.totalCount = null;
         } else {
             this.totalCount = totalCount;
         }
 
-        levelCount = Map.of(Level.INFO, 100,
-                Level.FINE, 50,
-                Level.FINER, 10,
-                Level.FINEST, 1);
-        
-        // Assuming printProgress configuration setting cannot be changed on the fly.
-        if (RuntimeEnvironment.getInstance().isPrintProgress()) {
+        // Note: Level.CONFIG is missing
+        final List<Level> standardLevels = Arrays.asList(Level.OFF, Level.SEVERE, Level.WARNING, Level.INFO,
+                Level.FINE, Level.FINER, Level.FINEST, Level.ALL);
+        int i = standardLevels.indexOf(baseLogLevel);
+        for (int num : new int[]{100, 50, 10, 1}) {
+            Level level = standardLevels.get(i);
+            if (level == null) {
+                break;
+            }
+            levelCountMap.put(level, num);
+            if (num == 1) {
+                break;
+            }
+            i++;
+        }
+
+        // Assuming the printProgress configuration setting cannot be changed on the fly.
+        if (!baseLogLevel.equals(Level.OFF) && RuntimeEnvironment.getInstance().isPrintProgress()) {
             spawnLogThread();
         }
     }
@@ -120,21 +158,7 @@ private void logLoop() {
 
             // Do not log if there was no progress.
             if (cachedCount < currentCount) {
-                if (currentCount <= 1 || (totalCount != null && currentCount == totalCount)) {
-                    currentLevel = Level.INFO;
-                } else {
-                    if (lastLoggedChunk.getOrDefault(Level.INFO, -1L) <
-                            currentCount / levelCount.get(Level.INFO)) {
-                        currentLevel = Level.INFO;
-                    } else if (lastLoggedChunk.getOrDefault(Level.FINE, -1L) <
-                            currentCount / levelCount.get(Level.FINE)) {
-                        currentLevel = Level.FINE;
-                    } else if (lastLoggedChunk.getOrDefault(Level.FINER, -1L) <
-                            currentCount / levelCount.get(Level.FINER)) {
-                        currentLevel = Level.FINER;
-                    }
-                }
-
+                currentLevel = getLevel(lastLoggedChunk, currentCount, currentLevel);
                 logIt(lastLoggedChunk, currentCount, currentLevel);
             }
 
@@ -159,9 +183,27 @@ private void logLoop() {
         }
     }
 
+    @VisibleForTesting
+    Level getLevel(Map<Level, Long> lastLoggedChunk, long currentCount, Level currentLevel) {
+        // The intention is to log the initial and final count at the base log level.
+        if (currentCount <= 1 || (totalCount != null && currentCount == totalCount)) {
+            currentLevel = baseLogLevel;
+        } else {
+            // Set the log level based on the "buckets".
+            for (Level level : levelCountMap.keySet()) {
+                if (lastLoggedChunk.getOrDefault(level, -1L) <
+                        currentCount / levelCountMap.get(level)) {
+                    currentLevel = level;
+                    break;
+                }
+            }
+        }
+        return currentLevel;
+    }
+
     private void logIt(Map<Level, Long> lastLoggedChunk, long currentCount, Level currentLevel) {
         if (logger.isLoggable(currentLevel)) {
-            lastLoggedChunk.put(currentLevel, currentCount / levelCount.get(currentLevel));
+            lastLoggedChunk.put(currentLevel, currentCount / levelCountMap.get(currentLevel));
             StringBuilder stringBuilder = new StringBuilder();
             stringBuilder.append("Progress: ");
             stringBuilder.append(currentCount);

opengrok-indexer/src/test/java/org/opengrok/indexer/util/ProgressTest.java

@@ -18,7 +18,7 @@
  */
 
 /*
- * Copyright (c) 2019, 2021, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2019, 2023, Oracle and/or its affiliates. All rights reserved.
  */
 package org.opengrok.indexer.util;
 
@@ -33,12 +33,14 @@
 import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeUnit;
+import java.util.logging.Level;
 import java.util.logging.Logger;
 
 import static org.junit.jupiter.api.Assertions.assertNotNull;
 import static org.junit.jupiter.api.Assertions.assertSame;
 import static org.mockito.ArgumentMatchers.any;
 import static org.mockito.ArgumentMatchers.anyString;
+import static org.mockito.ArgumentMatchers.same;
 import static org.mockito.Mockito.atLeast;
 import static org.mockito.Mockito.times;
 
@@ -49,6 +51,14 @@ public static void setup() {
         RuntimeEnvironment.getInstance().setPrintProgress(true);
     }
 
+    @Test
+    void testShifting() {
+        final Logger logger = Mockito.mock(Logger.class);
+        try (Progress progress = new Progress(logger, "xxx")) {
+            assertNotNull(progress);
+        }
+    }
+
     @Test
     public void testProgress() throws InterruptedException {
         final Logger logger = Mockito.mock(Logger.class);
@@ -85,6 +95,10 @@ public void testProgress() throws InterruptedException {
         assertSame(loggerThread.getState(), Thread.State.TERMINATED);
 
         Mockito.verify(logger, times(totalCount)).log(any(), anyString());
+        Mockito.verify(logger, atLeast(1)).log(same(Level.INFO), anyString());
+        Mockito.verify(logger, atLeast(2)).log(same(Level.FINE), anyString());
+        Mockito.verify(logger, atLeast(10)).log(same(Level.FINER), anyString());
+        Mockito.verify(logger, atLeast(50)).log(same(Level.FINEST), anyString());
     }
 
     @Test