Merge pull request #2 from avaje/feature/dynamic-log-level-debug

Add support for debug logging when dynamically changing log levels

Author: rbygrave

avaje-simple-json-logger/src/main/java/io/avaje/simplelogger/LoggerContext.java

@@ -24,6 +24,8 @@ static LoggerContext get() {
 
   /**
    * Apply a set of name log level pairs and update log levels for all impacted loggers.
+   *
+   * @return Map of changed loggers and their new levels.
    */
-  void putAll(Map<String, String> nameLevels);
+  Map<String, String> putAll(Map<String, String> nameLevels);
 }

avaje-simple-json-logger/src/main/java/io/avaje/simplelogger/encoder/SimpleLogger.java

@@ -19,9 +19,11 @@ final class SimpleLogger extends LegacyAbstractLogger {
     this.level = level;
   }
 
-  void setNewLevel(int newLevel) {
+  boolean setNewLevel(int newLevel) {
     // atomic assignment
-    this.level = newLevel;
+    final boolean changed = level != newLevel;
+    level = newLevel;
+    return changed;
   }
 
   @Override

avaje-simple-json-logger/src/main/java/io/avaje/simplelogger/encoder/SimpleLoggerFactory.java

@@ -5,6 +5,7 @@
 import org.slf4j.spi.LocationAwareLogger;
 
 import java.util.Map;
+import java.util.TreeMap;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ConcurrentMap;
 
@@ -46,16 +47,40 @@ static int stringToLevel(String levelStr) {
     return LocationAwareLogger.INFO_INT;
   }
 
+  static String level(int level) {
+    switch (level) {
+      case LocationAwareLogger.TRACE_INT:
+        return "trace";
+      case LocationAwareLogger.DEBUG_INT:
+        return "debug";
+      case LocationAwareLogger.INFO_INT:
+        return "info";
+      case LocationAwareLogger.WARN_INT:
+        return "warn";
+      case LocationAwareLogger.ERROR_INT:
+        return "error";
+      case LOG_LEVEL_OFF:
+        return "off";
+      default:
+        return "Level" + level;
+    }
+  }
+
   @Override
-  public void putAll(Map<String, String> nameLevels) {
+  public Map<String, String> putAll(Map<String, String> nameLevels) {
     nameLevels.forEach(this::putLevel);
 
+    final Map<String, String> changed = new TreeMap<>();
     for (Map.Entry<String, SimpleLogger> entry : loggerMap.entrySet()) {
       final String key = entry.getKey();
       if (adjustedKey(key, nameLevels)) {
-        entry.getValue().setNewLevel(level(key));
+        int newLevel = level(key);
+        if (entry.getValue().setNewLevel(newLevel)) {
+          changed.put(key, level(newLevel));
+        }
       }
     }
+    return changed;
   }
 
   private boolean adjustedKey(String key, Map<String, String> nameLevels) {

avaje-simple-logger/src/main/java/io/avaje/simplelogger/dynamic/DynamicLogLevels.java

@@ -4,6 +4,8 @@
 import io.avaje.config.ConfigurationPlugin;
 import io.avaje.config.ModificationEvent;
 import io.avaje.simplelogger.LoggerContext;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.util.HashMap;
 import java.util.Map;
@@ -13,6 +15,8 @@
  */
 public final class DynamicLogLevels implements ConfigurationPlugin {
 
+  private static final Logger log = LoggerFactory.getLogger("io.avaje.simplelogger");
+
   private static String trimKey(String key) {
     return key.substring(10);
   }
@@ -24,11 +28,14 @@ public void apply(Configuration configuration) {
     for (String key : config.keys()) {
       String rawLevel = config.getNullable(key);
       if (rawLevel != null) {
-        nameLevels.put(trimKey(key), rawLevel);
+        nameLevels.put(key, rawLevel);
       }
     }
     if (!nameLevels.isEmpty()) {
-      LoggerContext.get().putAll(nameLevels);
+      var changed = LoggerContext.get().putAll(nameLevels);
+      log.debug("apply log levels:{} changed loggers:{}", nameLevels, changed);
+    } else {
+      log.debug("dynamic log levels enabled");
     }
 
     configuration.onChange(this::onChangeAny);
@@ -47,7 +54,8 @@ private void onChangeAny(ModificationEvent modificationEvent) {
       });
 
     if (!nameLevels.isEmpty()) {
-      LoggerContext.get().putAll(nameLevels);
+      var changed = LoggerContext.get().putAll(nameLevels);
+      log.debug("apply log levels:{} changed loggers:{}", nameLevels, changed);
     }
   }
 

avaje-simple-logger/src/test/java/io/avaje/simplelogger/dynamic/DynamicLogLevelsTest.java

@@ -1,27 +1,42 @@
 package io.avaje.simplelogger.dynamic;
 
 
+import io.avaje.config.Config;
+import io.avaje.config.Configuration;
 import io.avaje.simplelogger.LoggerContext;
 import org.junit.jupiter.api.Test;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import java.util.Map;
 
+import static org.assertj.core.api.Assertions.assertThat;
+
 class DynamicLogLevelsTest {
 
   static final Logger logFoo = LoggerFactory.getLogger("org.foo.MyFoo");
   static final Logger logBar = LoggerFactory.getLogger("org.bar.extra.MyBar");
 
   @Test
   void test() {
+    Configuration configuration = Config.asConfiguration();
+    assertThat(configuration).isNotNull();
+
     logFoo.debug("hi foo");
     logBar.debug("hi bar before");
 
     LoggerContext.get()
       .putAll(Map.of("org.bar.extra", "trace"));
 
     logBar.debug("hi bar after log level change");
+
+    configuration.putAll(Map.of(
+      "junk", "junk",
+      "log.level.org.foo", "debug",
+      "log.level.org.bar.extra", "warn"));
+
+    logBar.debug("hi bar after dynamic log level change");
+    logFoo.debug("hi foo last");
   }
 
 }

avaje-simple-logger/src/test/resources/avaje-logger-test.properties

@@ -1,4 +1,5 @@
 ## can set config including log levels here
 
 log.level.org.foo=trace
-log.level.io.avaje.config=trace
+log.level.io.avaje.config=trace
+log.level.io.avaje.simplelogger=debug