Merge pull request #125 from avaje/feature/dynamic-logback-debug

dynamic-logback: improve debug logging

Author: rbygrave

avaje-aws-appconfig/src/main/java/io/avaje/config/appconfig/AppConfigFetcher.java

@@ -1,5 +1,7 @@
 package io.avaje.config.appconfig;
 
+import java.net.URI;
+
 interface AppConfigFetcher {
 
   static AppConfigFetcher.Builder builder() {
@@ -8,6 +10,8 @@ static AppConfigFetcher.Builder builder() {
 
   Result fetch() throws FetchException;
 
+  URI uri();
+
   class FetchException extends Exception {
 
     public FetchException(Exception e) {

avaje-aws-appconfig/src/main/java/io/avaje/config/appconfig/AppConfigPlugin.java

@@ -64,14 +64,16 @@ static final class Loader {
 
       var app = configuration.get("aws.appconfig.application");
       var env = configuration.get("aws.appconfig.environment");
-      var con = configuration.get("aws.appconfig.configuration", env + "-" + app);
+      var con = configuration.get("aws.appconfig.configuration", "default");
 
       this.fetcher = AppConfigFetcher.builder()
         .application(app)
         .environment(env)
         .configuration(con)
         .build();
 
+      log.log(DEBUG, "AwsAppConfig uri {0}", fetcher.uri());
+
       boolean pollEnabled = configuration.enabled("aws.appconfig.pollingEnabled", true);
       long pollSeconds = configuration.getLong("aws.appconfig.pollingSeconds", 45L);
       this.nextRefreshSeconds = configuration.getLong("aws.appconfig.refreshSeconds", pollSeconds - 1);

avaje-aws-appconfig/src/main/java/io/avaje/config/appconfig/DAppConfigFetcher.java

@@ -17,6 +17,11 @@ final class DAppConfigFetcher implements AppConfigFetcher {
       .build();
   }
 
+  @Override
+  public URI uri() {
+    return uri;
+  }
+
   @Override
   public AppConfigFetcher.Result fetch() throws FetchException {
     HttpRequest request = HttpRequest.newBuilder()

avaje-dynamic-logback/pom.xml

@@ -32,7 +32,19 @@
       <groupId>ch.qos.logback</groupId>
       <artifactId>logback-classic</artifactId>
       <version>1.5.0</version>
-      <scope>provided</scope>
+    </dependency>
+
+    <dependency>
+      <groupId>io.avaje</groupId>
+      <artifactId>avaje-applog-slf4j</artifactId>
+      <version>1.0</version>
+    </dependency>
+
+    <dependency>
+      <groupId>io.avaje</groupId>
+      <artifactId>junit</artifactId>
+      <version>1.4</version>
+      <scope>test</scope>
     </dependency>
 
   </dependencies>

avaje-dynamic-logback/src/main/java/io/avaje/config/dynamiclogback/LogbackPlugin.java

@@ -10,6 +10,7 @@
 import org.slf4j.LoggerFactory;
 
 import static java.lang.System.Logger.Level.DEBUG;
+import static java.lang.System.Logger.Level.TRACE;
 
 /**
  * Plugin to dynamically adjust the log levels via configuration changes.
@@ -25,14 +26,14 @@ public void apply(Configuration configuration) {
     for (String key : config.keys()) {
       String rawLevel = config.getNullable(key);
       setLogLevel(key, loggerContext, rawLevel);
+      log.log(TRACE, "log level {0} for {1}", rawLevel, key);
     }
     configuration.onChange(this::onChangeAny);
   }
 
   private static void setLogLevel(String key, LoggerContext loggerContext, String level) {
     Logger logger = loggerContext.getLogger(key);
     if (logger != null && level != null) {
-      log.log(DEBUG, "logger change for {0} to {1}", key, level);
       logger.setLevel(Level.toLevel(level));
     }
   }
@@ -43,8 +44,10 @@ private void onChangeAny(ModificationEvent modificationEvent) {
     modificationEvent.modifiedKeys().stream()
       .filter(key -> key.startsWith("log.level."))
       .forEach(key -> {
-        String rawLevel = config.getNullable(key.substring(10));
-        setLogLevel(key, loggerContext, rawLevel);
+        String logKey = key.substring(10);
+        String rawLevel = config.getNullable(key);
+        setLogLevel(logKey, loggerContext, rawLevel);
+        log.log(DEBUG, "set log level {0} for {1}", rawLevel, logKey);
       });
   }
 

avaje-dynamic-logback/src/test/java/io/avaje/config/dynamiclogback/LogbackPluginTest.java

@@ -0,0 +1,21 @@
+package io.avaje.config.dynamiclogback;
+
+import io.avaje.config.Configuration;
+import org.junit.jupiter.api.Test;
+
+import java.util.Map;
+
+class LogbackPluginTest {
+
+  @Test
+  void apply() {
+    Configuration config = Configuration.builder()
+      .put("log.level.other.Foo", "DEBUG")
+      .build();
+
+    var plugin = new LogbackPlugin();
+    plugin.apply(config);
+
+    config.putAll(Map.of("log.level.other.Foo", "INFO", "log.level.my.Bar", "TRACE"));
+  }
+}

avaje-dynamic-logback/src/test/resources/logback-test.xml

@@ -0,0 +1,14 @@
+<configuration>
+  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <root level="DEBUG">
+    <appender-ref ref="STDOUT"/>
+  </root>
+
+  <logger name="io.avaje" level="TRACE"/>
+
+</configuration>