springlogbackslf4jrollingfileappenderconsoleappender

ConsoleAppender logs are getting printed in the file specified by RollingFileAppender


I am using java based configuration for logging and trying to configure both ConsoleAppender and RollingFileAppender. Problem here is logs which are supposed to get printed on the console are getting printed in the log file. How to separate both logging to their respective locations?

package com.rsa.springclasses.day3.logback;

import java.io.IOException;
import java.util.Iterator;
import java.util.Properties;

import org.slf4j.LoggerFactory;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.ComponentScan;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.io.ClassPathResource;

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.Appender;
import ch.qos.logback.core.ConsoleAppender;
import ch.qos.logback.core.rolling.RollingFileAppender;
import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy;
import ch.qos.logback.core.rolling.TimeBasedRollingPolicy;

@Configuration
@ComponentScan
public class AppConfig {
  @Bean
  public LoggerContext getLoggerContext() {
    LoggerContext lctx = this.initLoggerContext();
    return lctx;
  }

  public LoggerContext initLoggerContext() {
    LoggerContext lctx = (LoggerContext) LoggerFactory.getILoggerFactory();
    lctx.setName("ApplicationLogger");
    Properties lp = readLogbackProperties();

    this.setLoggerLevels(lctx, lp);
    for (Logger l : lctx.getLoggerList()) {
        System.out.println("Logger name: " + l.getName() + ", Log Level: " + l.getLevel());
    }       

    PatternLayoutEncoder ple = this.getPatternEncoder(lp);
    ple.setContext(lctx);
    ple.stop();
    ple.start();
    System.out.println("Log pattern used: " + ple.getPattern());

    // Appenders
    ConsoleAppender<ILoggingEvent> capp = this.getConsoleAppender();
    capp.setContext(lctx);
    capp.setEncoder(ple);
    capp.stop();
    capp.start();

    RollingFileAppender<ILoggingEvent> rfapp = this.getRollingFileAdapter(lctx, ple);
    rfapp.stop();
    rfapp.start();

    Logger rootLogger = lctx.getLogger(Logger.ROOT_LOGGER_NAME);

    lctx.stop();

    rootLogger.detachAndStopAllAppenders();
    rootLogger.addAppender(rfapp);
    rootLogger.addAppender(capp);

    Iterator<Appender<ILoggingEvent>> apps = rootLogger.iteratorForAppenders();
    while(apps.hasNext()) {
        Appender<ILoggingEvent> app = apps.next();
        System.out.println("Appender added: " + app.getName());
    }
    lctx.start();
    rootLogger.debug("Logger context created.");
    return lctx;
  }

  public RollingFileAppender<ILoggingEvent> getRollingFileAdapter(LoggerContext lctx, PatternLayoutEncoder ple) {
    RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<ILoggingEvent>();
    appender.setName("ApplicationRollingFileAppender");
    appender.setFile("target/log/application.log");
    appender.setContext(lctx);
    appender.setEncoder(ple);

    TimeBasedRollingPolicy<ILoggingEvent> rollingPolicy = new TimeBasedRollingPolicy<>();
    rollingPolicy.setContext(lctx);
    rollingPolicy.setParent(appender);
    rollingPolicy.setFileNamePattern("target/log/application.%d{yyyy-MMM-dd_HH:mm:ss}.log");
    rollingPolicy.setMaxHistory(30);

    SizeBasedTriggeringPolicy<ILoggingEvent> triggeringPolicy = new SizeBasedTriggeringPolicy<>();
    triggeringPolicy.setContext(lctx);
    triggeringPolicy.setMaxFileSize("1KB");

    appender.setRollingPolicy(rollingPolicy);
    appender.setTriggeringPolicy(triggeringPolicy);

    rollingPolicy.stop();
    triggeringPolicy.stop();
    rollingPolicy.start();
    triggeringPolicy.start();

    return appender;
  }

  public ConsoleAppender<ILoggingEvent> getConsoleAppender() {
    ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
    appender.setName("ApplicationConsoleAppender");
    return appender;
  }

  public PatternLayoutEncoder getPatternEncoder(Properties props) {
    if (props == null) {
        props = this.readLogbackProperties();
    }
    String pattern = "%msg%n";
    if (props.containsKey("PATTERN")) {
        pattern = props.getProperty("PATTERN");
    }
    PatternLayoutEncoder ple = new PatternLayoutEncoder();
    ple.setPattern(pattern);
    return ple;
  }

  public void setLoggerLevels(LoggerContext lctx, Properties props) {
    if (props == null) {
        props = this.readLogbackProperties();
    }
    for(String lname: props.stringPropertyNames()) {
        if (lname.startsWith("SET_LOGBACK_LEVEL_")) {
            String level = props.getProperty(lname);
            String pname = lname.substring(18);
            lctx.getLogger(pname).setLevel(Level.valueOf(level));
        }
    }
  }

  public Properties readLogbackProperties() {
    ClassPathResource cpr = new ClassPathResource("day3/logback/logback.properties");
    Properties p = new Properties();
    try {
        p.load(cpr.getInputStream());
    } catch (IOException e) {
        throw new IllegalArgumentException("Failed to find day3/logback/logback.properties in classpath. " + e.getMessage());
    } catch (IllegalArgumentException iae) {
        throw new IllegalArgumentException("Failed to read day3/logback/logback.properties in classpath. File might contain a malformed Unicode escape sequence. " + iae.getMessage());
    }
    return p;
  }
}

Junit test

public class AppConfigJunitTest {
  @Autowired
  LoggerContext lctx;

  @Test
  public void testLoggerContext() {
    Logger logger = lctx.getLogger(this.getClass());
    logger.debug("Debug message");
    logger.error("Error message");
    logger.info("Info message");
    logger.trace("Trace message");
    logger.warn("Warn message");
    assertNotNull(lctx);
  }
}

Output that is getting printed on the cosole:

Logger name: ROOT, Log Level: DEBUG
Logger name: com, Log Level: null
Logger name: com.rsa, Log Level: null
Logger name: com.rsa.springclasses, Log Level: null
Logger name: com.rsa.springclasses.day3, Log Level: null
Logger name: com.rsa.springclasses.day3.logback, Log Level: DEBUG
Logger name: com.rsa.springclasses.day3.logback.AppConfigJunitTest, Log Level: DEBUG
Logger name: org, Log Level: null
Logger name: org.hibernate, Log Level: ERROR
Logger name: org.hibernate.type, Log Level: ERROR
Log pattern used: %date{yyyy-MMM-dd_HH:mm:ss.SSS} [%thread] %-5level %logger{36} %msg%n
Appender added: ApplicationRollingFileAppender
Appender added: ApplicationConsoleAppender

Logs that are getting printed in the log file:

2016-Aug-18_22:50:31.862 [main] DEBUG ROOT Logger context created.
2016-Aug-18_22:50:31.862 [main] DEBUG ROOT Logger context created.
2016-Aug-18_22:50:31.909 [main] DEBUG c.r.s.d.logback.AppConfigJunitTest Debug message
2016-Aug-18_22:50:31.909 [main] DEBUG c.r.s.d.logback.AppConfigJunitTest Debug message
2016-Aug-18_22:50:31.909 [main] ERROR c.r.s.d.logback.AppConfigJunitTest Error message
2016-Aug-18_22:50:31.909 [main] ERROR c.r.s.d.logback.AppConfigJunitTest Error message
2016-Aug-18_22:50:31.909 [main] INFO  c.r.s.d.logback.AppConfigJunitTest Info message
2016-Aug-18_22:50:31.909 [main] INFO  c.r.s.d.logback.AppConfigJunitTest Info message
2016-Aug-18_22:50:31.909 [main] WARN  c.r.s.d.logback.AppConfigJunitTest Warn message
2016-Aug-18_22:50:31.909 [main] WARN  c.r.s.d.logback.AppConfigJunitTest Warn message

Solution

  • I changed AppConfig.class as below that solved my issue. Basically we need to have separate PatternLayoutEncoder for console and RollingFileAppender. However SizeAndTimeBasedFNATP still not working. Will raise a separate thread for the same.

    package com.rsa.springclasses.day3.logback;
    
    import java.io.File;
    import java.io.IOException;
    import java.util.Iterator;
    import java.util.Properties;
    
    import org.slf4j.LoggerFactory;
    import org.springframework.context.annotation.Bean;
    import org.springframework.context.annotation.ComponentScan;
    import org.springframework.context.annotation.Configuration;
    import org.springframework.core.io.ClassPathResource;
    
    import ch.qos.logback.classic.Level;
    import ch.qos.logback.classic.Logger;
    import ch.qos.logback.classic.LoggerContext;
    import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
    import ch.qos.logback.classic.spi.ILoggingEvent;
    import ch.qos.logback.core.Appender;
    import ch.qos.logback.core.ConsoleAppender;
    import ch.qos.logback.core.rolling.RollingFileAppender;
    import ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP;
    import ch.qos.logback.core.rolling.TimeBasedRollingPolicy;
    import ch.qos.logback.core.status.OnConsoleStatusListener;
    import ch.qos.logback.core.status.StatusManager;
    
    @Configuration
    @ComponentScan
    public class AppConfig {
      @Bean
      public LoggerContext getLoggerContext() {
        LoggerContext lctx = this.initLoggerContext();
        return lctx;
      }
    
      public LoggerContext initLoggerContext() {
        LoggerContext lctx = (LoggerContext) LoggerFactory.getILoggerFactory();
        lctx.setName("ApplicationLogger");
        lctx.reset();
    
        StatusManager sm = lctx.getStatusManager();
        OnConsoleStatusListener ocsl = new OnConsoleStatusListener();
        sm.add(ocsl);
        ocsl.start();
    
        Properties lp = readLogbackProperties();
    
        PatternLayoutEncoder cple = this.getPatternEncoder(lp);
        cple.setContext(lctx);
        //cple.stop();
        cple.start();
        System.out.println("Console logging pattern used: " + cple.getPattern());
    
        // Appenders
        ConsoleAppender<ILoggingEvent> capp = this.getConsoleAppender();
        capp.setContext(lctx);
        capp.setEncoder(cple);
        //capp.stop();
        capp.start();
        System.out.println("Console appender started...");
    
        PatternLayoutEncoder fple = this.getPatternEncoder(lp);
        fple.setContext(lctx);
        //fple.stop();
        fple.start();
        System.out.println("File logging pattern used: " + fple.getPattern());
    
        RollingFileAppender<ILoggingEvent> rfapp = this.getRollingFileAdapter(lctx, fple, lp);
        //rfapp.stop();
        rfapp.start();
    
        Logger rootLogger = lctx.getLogger(Logger.ROOT_LOGGER_NAME);
        //lctx.stop();
    
        rootLogger.detachAndStopAllAppenders();
        rootLogger.addAppender(rfapp);
        rootLogger.addAppender(capp);
    
        this.setLoggerLevels(lctx, lp);
        for (Logger l : lctx.getLoggerList()) {
            System.out.println("Logger name: " + l.getName() + ", Log Level: " + l.getLevel());
        }
    
        lctx.start();
        rootLogger.debug("Logger context created.");
    
        Iterator<Appender<ILoggingEvent>> apps = rootLogger.iteratorForAppenders();
        while(apps.hasNext()) {
            Appender<ILoggingEvent> app = apps.next();
            System.out.println("Appenders available: " + app.getName());
        }
    
        return lctx;
      }
    
      public RollingFileAppender<ILoggingEvent> getRollingFileAdapter(LoggerContext lctx, PatternLayoutEncoder ple, Properties lp) {
        File logsdir = this.getLogDir(lp);
        String logsFileName = "application.log";
        if (lp.getProperty("FILE_NAME") != null) {
            logsFileName = lp.getProperty("FILE_NAME");
        }
        String logsRollPattern = "application.%d{yyyy-MMM-dd_HH:mm:ss}.log";
        if (lp.getProperty("ROLL_FILE_NAME_PATTERN") != null) {
            logsRollPattern = lp.getProperty("ROLL_FILE_NAME_PATTERN");
        }
        System.out.println("File rolling pattern used: " + logsRollPattern);
        RollingFileAppender<ILoggingEvent> appender = new RollingFileAppender<ILoggingEvent>();
        appender.setName("ApplicationRollingFileAppender");
        appender.setFile(logsdir.getAbsolutePath().replaceAll("\\\\", "/") + "/" + logsFileName);
        appender.setContext(lctx);
        appender.setEncoder(ple);
        appender.setAppend(true);
    
        SizeAndTimeBasedFNATP<ILoggingEvent> stbf = new SizeAndTimeBasedFNATP<>();
        stbf.setContext(lctx);
        stbf.setMaxFileSize("2KB");
    
        TimeBasedRollingPolicy<ILoggingEvent> rollingPolicy = new TimeBasedRollingPolicy<>();
        rollingPolicy.setContext(lctx);
        rollingPolicy.setParent(appender);
        rollingPolicy.setFileNamePattern(logsdir.getAbsolutePath().replaceAll("\\\\", "/") + "/" + logsRollPattern);
        rollingPolicy.setMaxHistory(30);
        rollingPolicy.setTimeBasedFileNamingAndTriggeringPolicy(stbf);
    
        stbf.setTimeBasedRollingPolicy(rollingPolicy);
        //rollingPolicy.stop();
        rollingPolicy.start();
        stbf.start();
    
        appender.setRollingPolicy(rollingPolicy);
    
        return appender;
      }
    
      public ConsoleAppender<ILoggingEvent> getConsoleAppender() {
        ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
        appender.setName("ApplicationConsoleAppender");
        return appender;
      }
    
      public PatternLayoutEncoder getPatternEncoder(Properties props) {
        if (props == null) {
            props = this.readLogbackProperties();
        }
        String pattern = "%msg%n";
        if (props.containsKey("PATTERN")) {
            pattern = props.getProperty("PATTERN");
        }
        PatternLayoutEncoder ple = new PatternLayoutEncoder();
        ple.setPattern(pattern);
        return ple;
      }
    
      public void setLoggerLevels(LoggerContext lctx, Properties props) {
        if (props == null) {
            props = this.readLogbackProperties();
        }
        for(String lname: props.stringPropertyNames()) {
            if (lname.startsWith("SET_LOGBACK_LEVEL_")) {
                String level = props.getProperty(lname);
                String pname = lname.substring(18);
                lctx.getLogger(pname).setLevel(Level.valueOf(level));
            }
        }
      }
    
      public File getLogDir(Properties lp) {
        if (lp == null) {
            lp = this.readLogbackProperties();
        }
        if (lp.getProperty("LOGSDIR") == null) {
            throw new IllegalArgumentException("LOGSDIR property not found in logback.properties");
        }
        File logsdir = new File(lp.getProperty("LOGSDIR"));
        if (logsdir.exists()) {
            System.out.println("Directory already available: " + logsdir.getAbsolutePath());
        } else {
            logsdir.mkdirs();
            System.out.println("Directory created: " + logsdir.getAbsolutePath());
        }
        return logsdir;
      }
    
      public Properties readLogbackProperties() {
        ClassPathResource cpr = new ClassPathResource("day3/logback/logback.properties");
        System.out.println("File used to load the logback properties: " + cpr.getPath());
        Properties p = new Properties();
        try {
            p.load(cpr.getInputStream());
        } catch (IOException e) {
            throw new IllegalArgumentException("Failed to find day3/logback/logback.properties in classpath. " + e.getMessage());
        } catch (IllegalArgumentException iae) {
            throw new IllegalArgumentException("Failed to read day3/logback/logback.properties in classpath. File might contain a malformed Unicode escape sequence. " + iae.getMessage());
        }
        return p;
      }
    }