logger(二)logback簡介及其實現原理

一、logback簡介

logback是log4j創始人寫的，性能比log4j要好，目前主要分為3個模塊

1. logback-core:核心代碼模塊
2. logback-classic:log4j的一個改良版本，同時實現了slf4j的接口，這樣你如果之后要切換其他日志組件也是一件很容易的事
3. logback-access:訪問模塊與Servlet容器集成提供通過Http來訪問日志的功能

二、logback.xml配置

<?xml version="1.0" encoding="UTF-8"?>
<!--debug 要不要打印 logback內部日志信息，true則表示要打印。建議開啟-->
<!--scan 配置發送改變時，要不要重新加載-->
<configuration debug="true" scan="true" scanPeriod="1 seconds">
    <contextName>logback</contextName>
    <!--定義參數,后面可以通過${app.name}使用-->
    <property name="app.name" value="logback_test"/>
    <!--ConsoleAppender 用於在屏幕上輸出日志-->
    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <!--定義了一個過濾器,在LEVEL之下的日志輸出不會被打印出來-->
        <!--這里定義了DEBUG，也就是控制台不會輸出比ERROR級別小的日志-->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>DEBUG</level>
        </filter>
        <!-- encoder 默認配置為PatternLayoutEncoder -->
        <!--定義控制台輸出格式-->
        <encoder>
            <pattern>%d [%thread] %-5level %logger{36} [%file : %line] - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--定義日志輸出的路徑-->
        <!--這里的scheduler.manager.server.home 沒有在上面的配置中設定，所以會使用java啟動時配置的值-->
        <!--比如通過 java -Dscheduler.manager.server.home=/path/to XXXX 配置該屬性-->
        <file>${scheduler.manager.server.home}/logs/${app.name}.log</file>
        <!--定義日志滾動的策略TimeBasedRollingPolicy： 最常用的滾動策略，它根據時間來制定滾動策略，
          既負責滾動也負責出發滾動。有以下子節點：<fileNamePattern>:必要節點，包含文件名及“%d”轉換符， 
          “%d”可以包含一個java.text.SimpleDateFormat指定的時間格式，如：%d{yyyy-MM}。如果直接使用 %d-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--定義文件滾動時的文件名的格式-->
            <fileNamePattern>${scheduler.manager.server.home}/logs/${app.name}.%d{yyyy-MM-dd.HH}.log.gz
            </fileNamePattern>
            <!--60天的時間周期，日志量最大20GB-->
            <maxHistory>60</maxHistory>
            <!-- 該屬性在 1.1.6版本后 才開始支持-->
            <totalSizeCap>20GB</totalSizeCap>
        </rollingPolicy>
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <!--每個日志文件最大100MB-->
            <maxFileSize>100MB</maxFileSize>
        </triggeringPolicy>
        <!--定義輸出格式-->
        <encoder>
            <pattern>%d [%thread] %-5level %logger{36} [%file : %line] - %msg%n</pattern>
        </encoder>
    </appender>

    <!--root是默認的logger 這里設定輸出級別是debug-->
    <root level="info">
        <!--定義了兩個appender，日志會通過往這兩個appender里面寫-->
        <appender-ref ref="stdout"/>
        <appender-ref ref="file"/>
    </root>
    <!--對於類路徑以 com.example.logback 開頭的Logger,輸出級別設置為warn,並且只輸出到控制台-->
    <!--這個logger沒有指定appender，它會繼承root節點中定義的那些appender-->
    <logger name="com.example.logback" level="warn"/>

    <!--通過 LoggerFactory.getLogger("mytest") 可以獲取到這個logger-->
    <!--由於這個logger自動繼承了root的appender，root中已經有stdout的appender了，自己這邊又引入了stdout的appender-->
    <!--如果沒有設置 additivity="false" ,就會導致一條日志在控制台輸出兩次的情況-->
    <!--additivity表示要不要使用rootLogger配置的appender進行輸出-->
    <logger name="mytest" level="info" additivity="false">
        <appender-ref ref="stdout"/>
    </logger>
    
    <!--由於設置了 additivity="false" ，所以輸出時不會使用rootLogger的appender-->
    <!--但是這個logger本身又沒有配置appender，所以使用這個logger輸出日志的話就不會輸出到任何地方-->
    <logger name="mytest2" level="info" additivity="false"/>
</configuration>

 

三、實現原理

1、獲取LoggerFactory

slf4j委托具體實現框架的StaticLoggerBinder來返回一個ILoggerFactory，從而對接到具體實現框架上，我們看下這個類(省略了部分代碼)

public class StaticLoggerBinder implements LoggerFactoryBinder {

  private static StaticLoggerBinder SINGLETON = new StaticLoggerBinder();static {
    SINGLETON.init();
  }public static StaticLoggerBinder getSingleton() {
    return SINGLETON;
  }/**
   * Package access for testing purposes.
   */
  void init() {
    try {
      try {
        new ContextInitializer(defaultLoggerContext).autoConfig();
      } catch (JoranException je) {
        Util.report("Failed to auto configure default logger context", je);
      }
      // logback-292
      if(!StatusUtil.contextHasStatusListener(defaultLoggerContext)) {
        StatusPrinter.printInCaseOfErrorsOrWarnings(defaultLoggerContext);
      }
      contextSelectorBinder.init(defaultLoggerContext, KEY);
      initialized = true;
    } catch (Throwable t) {
      // we should never get here
      Util.report("Failed to instantiate [" + LoggerContext.class.getName()
          + "]", t);
    }
  }
  public ILoggerFactory getLoggerFactory() {
    if (!initialized) {
      return defaultLoggerContext;
    }

    if (contextSelectorBinder.getContextSelector() == null) {
      throw new IllegalStateException(
          "contextSelector cannot be null. See also " + NULL_CS_URL);
    }
    return contextSelectorBinder.getContextSelector().getLoggerContext();
  }
}

可以看到

• 1、通過getSingleton()獲取該類的單例
• 2、static塊來保證初始化調用init()方法
• 3、在init方法中，委托ContextInitializer類對LoggerContext進行初始化。這里如果找到了任一配置文件，就會根據配置文件去初始化LoggerContext，如果沒找到，會使用默認配置。
• 4、然后初始化ContextSelectorStaticBinder，在這個類內部new一個DefaultContextSelector，並把第一步中配置完畢的LoggerContext傳給DefaultContextSelector
• 5、調用getLoggerFactory()方法，直接返回3中配置的LoggerContext，或者委托DefaultContextSelector類返回LoggerContext

這里可以看出所有的配置均保存在LoggerContext這個類中，只要獲取到了該類，就能得到log的所有配置，我們的logger就保存在該類的Map<String, Logger> loggerCache中，key為logger的name.

2、獲取logger

public final Logger getLogger(final String name) {

        if (name == null) {
            throw new IllegalArgumentException("name argument cannot be null");
        }

        // 如果請求的是ROOT Logger，那么就直接返回root
        if (Logger.ROOT_LOGGER_NAME.equalsIgnoreCase(name)) {
            return root;
        }

        int i = 0;
        Logger logger = root;

        // 請求的Logger是否已經創建過了，如果已經創建過，就直接從loggerCache中返回
        Logger childLogger = (Logger) loggerCache.get(name);
        // if we have the child, then let us return it without wasting time
        if (childLogger != null) {
            return childLogger;
        }

        // if the desired logger does not exist, them create all the loggers
        // in between as well (if they don't already exist)
        String childName;
        while (true) {
            int h = LoggerNameUtil.getSeparatorIndexOf(name, i);
            if (h == -1) {
                childName = name;
            } else {
                childName = name.substring(0, h);
            }
            i = h + 1;
            synchronized (logger) {
                childLogger = logger.getChildByName(childName);
                if (childLogger == null) {
                    //創建Logger實例
                    childLogger = logger.createChildByName(childName);
                    loggerCache.put(childName, childLogger);
                    incSize();
                }
            }
            logger = childLogger;
            if (h == -1) {
                return childLogger;
            }
        }
    }

3、logger.info()記錄日志

slf4j定義了Logger接口記錄日志的方法是info()、warn()、debug()等，這些方法只是入口，logback是這樣實現這些方法的 

public void info(String msg) {  
    filterAndLog_0_Or3Plus(FQCN, null, Level.INFO, msg, null, null);  
  } 

 當客戶端代碼調用Logger.info()時，實際上會進入filterAndLog_0_Or3Plus方法，Logger類中還有很多名字很相似的方法，比如filterAndLog_1、filterAndLog_2。

/** 
   * The next methods are not merged into one because of the time we gain by not 
   * creating a new Object[] with the params. This reduces the cost of not 
   * logging by about 20 nanoseconds. 
   */  
  
  private final void filterAndLog_0_Or3Plus(final String localFQCN,  
      final Marker marker, final Level level, final String msg,  
      final Object[] params, final Throwable t) {  
  
    final FilterReply decision = loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg,  params, t);  
    if (decision == FilterReply.NEUTRAL) {  
      if (effectiveLevelInt > level.levelInt) {  
        return;  
      }  
    } else if (decision == FilterReply.DENY) {  
      return;  
    }  
  
    buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);  
  } 

該方法首先要請求TurboFilter來判斷是否允許記錄這次日志信息。TurboFilter是快速篩選的組件，篩選發生在LoggingEvent創建之前，這種設計也是為了提高性能 

如果經過過濾，確定要記錄這條日志信息，則進入buildLoggingEventAndAppend方法 

private void buildLoggingEventAndAppend(final String localFQCN,  
      final Marker marker, final Level level, final String msg,  
      final Object[] params, final Throwable t) {  
    LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);  
    le.setMarker(marker);  
    callAppenders(le);  
  }  

在這個方法里，首先創建了LoggingEvent對象，然后調用callAppenders()方法，要求該Logger關聯的所有Appenders來記錄日志 

LoggingEvent對象是承載了日志信息的類，最后輸出的日志信息，就來源於這個事件對象 

/** 
   * Invoke all the appenders of this logger. 
   *  
   * @param event 
   *          The event to log 
   */  
  public void callAppenders(ILoggingEvent event) {  
    int writes = 0;  
    for (Logger l = this; l != null; l = l.parent) {  
      writes += l.appendLoopOnAppenders(event);  
      if (!l.additive) {  
        break;  
      }  
    }  
    // No appenders in hierarchy  
    if (writes == 0) {  
      loggerContext.noAppenderDefinedWarning(this);  
    }  
  }  

經過前面的Filter過濾、日志級別匹配、創建LoggerEvent對象，終於進入了記錄日志的方法。該方法會調用此Logger關聯的所有Appender，而且還會調用所有父Logger關聯的Appender，直到遇到父Logger的additive屬性設置為false為止，這也是為什么如果子Logger和父Logger都關聯了同樣的Appender，則日志信息會重復記錄的原因 

private int appendLoopOnAppenders(ILoggingEvent event) {  
    if (aai != null) {  
      return aai.appendLoopOnAppenders(event);  
    } else {  
      return 0;  
    }  
  }  

實際上調用的AppenderAttachableImpl的appendLoopOnAppenders()方法 

/** 
   * Call the <code>doAppend</code> method on all attached appenders. 
   */  
  public int appendLoopOnAppenders(E e) {  
    int size = 0;  
    r.lock();  
    try {  
      for (Appender<E> appender : appenderList) {  
        appender.doAppend(e);  
        size++;  
      }  
    } finally {  
      r.unlock();  
    }  
    return size;  
  }  

到這里，為了記錄一條日志信息，長長的調用鏈終於告一段落了，通過調用Appender的doAppend(LoggingEvent e)方法，委托Appender來最終記錄日志

UnsynchronizedAppenderBase里面的doAppend()方法，它主要是記錄了Status狀態，然后檢查Appender上的Filter是否滿足過濾條件，最后再調用實現子類的appender()方法。很眼熟是嗎，這里用到了一個設計模式——模板方法  

public void doAppend(E eventObject) {  
    // WARNING: The guard check MUST be the first statement in the  
    // doAppend() method.  
        
    // prevent re-entry.  
    if (Boolean.TRUE.equals(guard.get())) {  
      return;  
    }  
  
    try {  
      guard.set(Boolean.TRUE);  
  
      if (!this.started) {  
        if (statusRepeatCount++ < ALLOWED_REPEATS) {  
          addStatus(new WarnStatus(  
              "Attempted to append to non started appender [" + name + "].",  
              this));  
        }  
        return;  
      }  
  
      if (getFilterChainDecision(eventObject) == FilterReply.DENY) {  
        return;  
      }  
  
      // ok, we now invoke derived class' implementation of append  
      this.append(eventObject);  
  
    } catch (Exception e) {  
      if (exceptionCount++ < ALLOWED_REPEATS) {  
        addError("Appender [" + name + "] failed to append.", e);  
      }  
    } finally {  
      guard.set(Boolean.FALSE);  
    }  
  }  
  
  abstract protected void append(E eventObject); 

上面的代碼非常簡單，就不用說了，我們就直接看看實現類的append()方法是怎么實現的，這里我們選擇OutputStreamAppender實現類 

@Override  
  protected void append(E eventObject) {  
    if (!isStarted()) {  
      return;  
    }  
  
    subAppend(eventObject);  
  }  

首先檢查一下這個Appender是否已經啟動，如果沒啟動就直接返回，如果已經啟動，則又進入一個subAppend()方法 

RollingFileAppender覆蓋了subAppend()方法，實現了翻滾策略

@Override
    protected void subAppend(E event) {
        // The roll-over check must precede actual writing. This is the
        // only correct behavior for time driven triggers.

        // We need to synchronize on triggeringPolicy so that only one rollover
        // occurs at a time
        synchronized (triggeringPolicy) {
            if (triggeringPolicy.isTriggeringEvent(currentlyActiveFile, event)) {
                rollover();
            }
        }

        super.subAppend(event);
    }

進入super.subAppend(event);

protected void subAppend(E event) {
        if (!isStarted()) {
            return;
        }
        try {
            // this step avoids LBCLASSIC-139
            if (event instanceof DeferredProcessingAware) {
                ((DeferredProcessingAware) event).prepareForDeferredProcessing();
            }
            // the synchronization prevents the OutputStream from being closed while we
            // are writing. It also prevents multiple threads from entering the same
            // converter. Converters assume that they are in a synchronized block.
            // lock.lock();

            byte[] byteArray = this.encoder.encode(event);
            writeBytes(byteArray);

        } catch (IOException ioe) {
            // as soon as an exception occurs, move to non-started state
            // and add a single ErrorStatus to the SM.
            this.started = false;
            addStatus(new ErrorStatus("IO failure in appender", this, ioe));
        }
    }

通過this.encoder.encode(event)方法格式化需要記錄的日志，然后通過writeBytes(byteArray)寫入日志。

 

四、通過代碼動態生成logger對象

public class LoggerHolder {

    public static Logger getLogger(String name) {
        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
        //如果未創建該logger
        if (loggerContext.exists(name) == null) {
            return buildLogger(name);
        }
        //如果已經創建，則返回
        return loggerContext.getLogger(name);
    }

    private static Logger buildLogger(String name) {

        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
        Logger logger = loggerContext.getLogger(name);
        //配置rollingFileAppender
        RollingFileAppender rollingFileAppender = new RollingFileAppender();
        rollingFileAppender.setName(name);
        //配置rollingPolicy
        TimeBasedRollingPolicy rollingPolicy = new TimeBasedRollingPolicy();
        rollingPolicy.setFileNamePattern("/data/pjf/" + name + "/" + name + ".%d{yyyyMMdd}.log");
        rollingFileAppender.setRollingPolicy(rollingPolicy);
        //配置encoder
        PatternLayoutEncoder encoder = new PatternLayoutEncoder();
        encoder.setCharset(UTF_8);
        encoder.setPattern("%msg%n");
        rollingFileAppender.setEncoder(encoder);
        //配置logger
        logger.addAppender(rollingFileAppender);
        logger.setAdditive(false);
        logger.setLevel(Level.INFO);
        return logger;
    }
}

 

具體參考：寫的很詳細，

讀logback源碼系列文章（一）——對接slf4j

讀logback源碼系列文章（二）——提供ILoggerFactory

讀logback源碼系列文章（三）——創建Logger

讀logback源碼系列文章（四）——記錄日志

讀logback源碼系列文章（五）——Appender

讀logback源碼系列文章（六）——ContextInitializer

讀logback源碼系列文章（七）——配置的實際工作類Action

讀logback源碼系列文章（八）——記錄日志的實際工作類Encoder