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

[logback users list]

Hi again,

Of course, I sent the email after spending all morning on it and then I 
worked it out.
The problem was in the method I didn't send:

   @Override
   @SuppressWarnings("unchecked")
   public ExecutionStatus configure(LoggerContext lc) {
     configure(lc, !Strings.isNullOrEmpty(System.getenv(KUBERNETES_ENV_KEY)));
     return ExecutionStatus.DO_NOT_INVOKE_NEXT_IF_ANY;
   }

I was returning ExecutionStatus.NEUTRAL, which I think was allowing 
BasicConfigurator to run after mine.

As things stand now it shouldn't matter what order Configurators are 
called in, if mine is called first no others will be invoked and if mine 
is called last it clears everything else out.

Jim


On 04/05/2023 14:14, logback users list via logback-user wrote:
>
> 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 at qos.ch
> https://mailman.qos.ch/cgi-bin/mailman/listinfo/logback-user
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20230504/097ebe7e/attachment-0001.htm>