[logback-user] Getting duplicate messages when using a custom Configurator

[logback users list via logback-user]

Hi,

I have a custom Configurator installed via META_INF.services in a bunch 
of different services.
I do it this way because I was finding that managing logback.xml files 
across a lot of different services was awkward and unnecessary log 
levels were leaking into production.
I also have a custom class for changing specific log levels based on env 
vars or system properties, and a vertx router for changing them 
dynamically at runtime.

All of this has been working work a few years, but I have recently found 
that in some circumstances I'm getting duplicate messages (at first it 
was just in some builds, but now it's in production so I need to do 
something about it).

I've added a load of debug spew to my classes, but it appears that the 
default configuration is being applied after my custom Configurator and 
I can't work out what is causing that.
And, of course, right now I can only reproduce this by executing a jar 
on the command line, rather than in a unit test.

My main method looks like this:

  public static void main(String[] args) {
    Main main = new Main(args);
    logger.info("Starting ({})", LoggerFactory.getILoggerFactory());

    LoggerContext lc = ((LoggerContext) LoggerFactory.getILoggerFactory());
    System.out.println(lc.getName());
    for (ch.qos.logback.classic.Logger logger : lc.getLoggerList()) {
      System.out.println("\t" + logger.getName());
      for (Iterator<Appender<ILoggingEvent>> iter = 
logger.iteratorForAppenders(); iter.hasNext(); ) {
        Appender<ILoggingEvent> a = iter.next();
        System.out.println("\t\t" + a.getName());
      }
    }
    // irrelevant stuff here
  }

and my custom Configurator is this:

  /**
   * Perform the configuration.
   * @param lc The LoggerContext to configure.
   * @param asJson If true then logs will be recorded as JSON.
   */
  public void configure(LoggerContext lc, boolean asJson) {
    @SuppressWarnings("unchecked")
    Map<Object, Object> ruleRegistry = (Map<Object, Object>) 
lc.getObject(CoreConstants.PATTERN_RULE_REGISTRY);
    if (ruleRegistry == null) {
      ruleRegistry = new HashMap<>();
      lc.putObject(CoreConstants.PATTERN_RULE_REGISTRY, ruleRegistry);
    }
    registerConverters(ruleRegistry);

    Appender<ILoggingEvent> appender;
    if (asJson) {
      appender = configureJsonOutput(lc, createConsoleAppender(lc));
    } else {
      appender = configureMultiLineOutput(lc, createConsoleAppender(lc));
    }
    appender.start();
    
    System.out.println(lc.getName());
    for (Logger logger : lc.getLoggerList()) {
      System.out.println("\t" + logger.getName());
      for (Iterator<Appender<ILoggingEvent>> iter = 
logger.iteratorForAppenders(); iter.hasNext(); ) {
        Appender<ILoggingEvent> a = iter.next();
        System.out.println("\t\t" + a.getName());
      }
      logger.detachAndStopAllAppenders();
    }
    
    Logger rootLogger = lc.getLogger(Logger.ROOT_LOGGER_NAME);
    rootLogger.addAppender(appender);
    rootLogger.setLevel(Level.INFO);
    rootLogger.setAdditive(true);

    System.out.println(lc.getName());
    for (Logger logger : lc.getLoggerList()) {
      System.out.println("\t" + logger.getName());
      for (Iterator<Appender<ILoggingEvent>> iter = 
logger.iteratorForAppenders(); iter.hasNext(); ) {
        Appender<ILoggingEvent> a = iter.next();
        System.out.println("\t\t" + a.getName());
      }
    }
  }

The output from this is:

NOTE: Picked up JDK_JAVA_OPTIONS: -server -XX:-OmitStackTraceInFastThrow
default
        ROOT
default
        ROOT
                STDOUTPUT
2023-05-04 12:55:18.653 [main] c.groupgti.shared.configservice.Main INFO  - 
Starting (ch.qos.logback.classic.LoggerContext[default])
13:55:18.653 [main] INFO com.groupgti.shared.configservice.Main -- Starting 
(ch.qos.logback.classic.LoggerContext[default])
default
        ROOT
                STDOUTPUT
                console
        com
        com.groupgti
        com.groupgti.shared
        com.groupgti.shared.configservice
        com.groupgti.shared.configservice.Main
        + more packages


So my custom Configurator is running, but then (I think when the static 
loggers are created) the console appender is being added to the ROOT logger.

I tried naming my appender "console", that just resulted in two 
appenders called "console" :)

How can I stop the default "console" appender being added to root?

Thanks

Jim



_______________________________________________
logback-user mailing list
logback-user@qos.ch
https://mailman.qos.ch/cgi-bin/mailman/listinfo/logback-user