日誌？聊一聊slf4j吧

glmapper發表於2018-04-15

作為一個Java程式設計師，肯定對於日誌記錄不會陌生，無論專案大小，日誌記錄都是必須的；因為好的日誌可以很容易的幫助我們定位一些生產問題。

我懷念的是 無話不說 System.out.println("這裡是重要的日誌");

我懷念的是 一起作夢 System.err.println("這裡是錯誤的日誌");

對於日常開發來說，其實System.out.println挺好用的，但是為什麼在實際的開發應用中不使用這個來輸出日誌呢?

System.out.println()除了使用方便一點之外，其他感覺真的沒有什麼多大的用處。方便在哪兒呢？在Eclipse中你只需要輸入syso【IDEA中輸出sout即可】，然後按下程式碼提示鍵，這個方法就會自動出來了，相信這也是很多Java新手對它鍾情的原因，因為我一開始也是這麼幹的，直到...【此處省略淚水】。那缺點又在哪兒了呢？這個就太多了，比如日誌列印不可控制、列印時間無法確定、不能新增過濾器、日誌沒有級別區分……

記得我最開始接觸的是log4j，log4j作為Apache的一個開放原始碼的專案，通過使用log4j，我們可以控制日誌資訊輸送的目的地是控制檯、檔案等我們期望它輸出到的地方；我們也可以控制每一條日誌的輸出格式；通過定義每一條日誌資訊的級別，我們能夠更加細緻地控制日誌的生成過程。重要的是，這些可以通過一個配置檔案來靈活地進行配置，而不需要修改應用的程式碼。

確實，log4j作為最先比較流行的日誌框架，給我們在應用開發和維護帶來了很大的便捷，那麼為什麼這樣優秀的框架最後還是慢慢的走下“神壇”呢？而逐漸被logback代替呢？下面是摘自網上一位大佬對於這個問題的解釋：

無論從設計上還是實現上，Logback相對log4j而言有了相對多的改進。不過儘管難以一一細數，這裡還是列舉部分理由為什麼選擇logback而不是log4j。牢記logback與log4j在概念上面是很相似的，它們都是有同一群開發者建立。

  • 更快的執行速度

    基於我們先前在log4j上的工作，logback 重寫了內部的實現，在某些特定的場景上面，甚至可以比之前的速度快上10倍。在保證logback的元件更加快速的同時，同時所需的記憶體更加少。

  • 充分的測試

    Logback 歷經了幾年，數不清小時數的測試。儘管log4j也是測試過的，但是Logback的測試更加充分，跟log4j不在同一個級別。我們認為，這正是人們選擇Logback而不是log4j的最重要的原因。人們都希望即使在惡劣的條件下，你的日記框架依然穩定而可靠。

slf4j log4j logback

slf4j:The Simple Logging Facade for Java 即java的簡單日誌門面

簡答的講就是slf4j是一系列的日誌介面，slf4j作為一個日誌的抽象行為存在，但是並沒有提供真正的實現。

slf4j為各種日誌框架提供了一個統一的介面，使使用者可以用統一的介面記錄日誌，但是動態地決定真正的實現框架。logback，log4j，common-logging等框架都實現了這些介面。

slf4j 原始碼分析

想了很久都不知道從哪裡開頭寫比較合適，slf4j包中總共29個類【1.7.21版本】，不可能一一列舉。所以就從我們熟知的這個語句來說。

private static final Logger logger =
LoggerFactory.getLogger(DemoTest.class);
複製程式碼

上面這段程式碼其實就是我們平時在程式碼裡面申明一個日誌物件的常用方式。

先來看下Logger介面提供的方法；

package org.slf4j;

public interface Logger {
    //根Logger
    String ROOT_LOGGER_NAME = "ROOT";
    String getName();
    //判斷記錄器Trace跟蹤是否啟用;Trace跟蹤啟用後一般會列印比較詳細的資訊。
    boolean isTraceEnabled();
    //trace級別
    void trace(String var1);
    void trace(String var1, Object var2);
    void trace(String var1, Object var2, Object var3);
    void trace(String var1, Object... var2);
    void trace(String var1, Throwable var2);
    boolean isTraceEnabled(Marker var1);
    void trace(Marker var1, String var2);
    void trace(Marker var1, String var2, Object var3);
    void trace(Marker var1, String var2, Object var3, Object var4);
    void trace(Marker var1, String var2, Object... var3);
    void trace(Marker var1, String var2, Throwable var3);
    //進行預先判斷，提升系統效能
    boolean isDebugEnabled();
    void debug(String var1);
    void debug(String var1, Object var2);
    void debug(String var1, Object var2, Object var3);
    void debug(String var1, Object... var2);
    void debug(String var1, Throwable var2);
    boolean isDebugEnabled(Marker var1);
    void debug(Marker var1, String var2);
    void debug(Marker var1, String var2, Object var3);
    void debug(Marker var1, String var2, Object var3, Object var4);
    void debug(Marker var1, String var2, Object... var3);
    void debug(Marker var1, String var2, Throwable var3);
    //info級別
    boolean isInfoEnabled();
    void info(String var1);
    void info(String var1, Object var2);
    void info(String var1, Object var2, Object var3);
    void info(String var1, Object... var2);
    void info(String var1, Throwable var2);
    boolean isInfoEnabled(Marker var1);
    void info(Marker var1, String var2);
    void info(Marker var1, String var2, Object var3);
    void info(Marker var1, String var2, Object var3, Object var4);
    void info(Marker var1, String var2, Object... var3);
    void info(Marker var1, String var2, Throwable var3);
    //warn級別
    boolean isWarnEnabled();
    void warn(String var1);
    void warn(String var1, Object var2);
    void warn(String var1, Object... var2);
    void warn(String var1, Object var2, Object var3);
    void warn(String var1, Throwable var2);
    boolean isWarnEnabled(Marker var1);
    void warn(Marker var1, String var2);
    void warn(Marker var1, String var2, Object var3);
    void warn(Marker var1, String var2, Object var3, Object var4);
    void warn(Marker var1, String var2, Object... var3);
    void warn(Marker var1, String var2, Throwable var3);
    //error級別
    boolean isErrorEnabled();
    void error(String var1);
    void error(String var1, Object var2);
    void error(String var1, Object var2, Object var3);
    void error(String var1, Object... var2);
    void error(String var1, Throwable var2);
    boolean isErrorEnabled(Marker var1);
    void error(Marker var1, String var2);
    void error(Marker var1, String var2, Object var3);
    void error(Marker var1, String var2, Object var3, Object var4);
    void error(Marker var1, String var2, Object... var3);
    void error(Marker var1, String var2, Throwable var3);
}

複製程式碼

isXXXXEnabled

以isDebugEnabled來說明下這個isXXXXEnabled方法的作用。

logger.debug("the debug msg is " +doMethod());

假設我們的日誌級別設定為info,那這句話不會輸出日誌，但這個方法還是會呼叫（預判斷作用）。要呼叫這個方法，必須提供引數。doMethod()方法返回的結果就是引數的一部分。doMethod()要執行n秒鐘，n秒鐘後，進入到debug()方法裡；

但是日誌級別為info。結果是日誌雖然沒有輸出，卻花費了n秒鐘來構造引數。很顯然這裡得不償失的。儘管實際應用中幾乎不可能有這種花n秒鐘來構造這樣一個引數的情況，但如果併發數大的話，這樣寫還是會影響系統的效能的。這個時候，就應該寫成:

if(logger.isDebugEnabled()){
    logger.debug("the debug msg is " + doMethod());
} 
複製程式碼

接下來說LoggerFactory這個類；先從getLogger這個方法為入口來看下：

public static Logger getLogger(String name) {
    ILoggerFactory iLoggerFactory = getILoggerFactory();
    return iLoggerFactory.getLogger(name);
}

public static Logger getLogger(Class<?> clazz) {
    Logger logger = getLogger(clazz.getName());
    if (DETECT_LOGGER_NAME_MISMATCH) {
        Class<?> autoComputedCallingClass = Util.getCallingClass();
        if (autoComputedCallingClass != null && nonMatchingClasses(clazz, autoComputedCallingClass)) {
            Util.report(String.format("Detected logger name mismatch. Given name: \"%s\"; computed name: \"%s\".", logger.getName(), autoComputedCallingClass.getName()));
            Util.report("See http://www.slf4j.org/codes.html#loggerNameMismatch for an explanation");
        }
    }

    return logger;
}
複製程式碼

getLogger方法提供了兩種過載方式，一種是傳入一個name，用於標註當前日誌的名字。另外一個是提供一個Class物件，其實裡面也是通過clazz.getName()來作為日誌的名稱。

從上面的程式碼中可以比較明顯的看到ILoggerFactory這個介面。

package org.slf4j;

public interface ILoggerFactory {
    Logger getLogger(String var1);
}
複製程式碼

ILoggerFactory這個介面實際上就是為不同接入的日誌實現提供了統一的頂層型別；每個日誌框架都需要實現ILoggerFactory介面，來說明自己是怎麼提供Logger的。像log4j、logback能夠提供父子層級關係的Logger，就是在ILoggerFactory的實現類裡實現的。同時，它們也需要實現Logger介面，以完成記錄日誌。

logback中的實現

public class LoggerContext extends ContextBase implements
ILoggerFactory, LifeCycle
複製程式碼

上面提到過，對於不同的日誌框架的實現都實現了ILoggerFactory介面。

 @Override
public final Logger getLogger(final String name) {

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

    // if we are asking for the root logger, then let us return it without
    // wasting time
    if (Logger.ROOT_LOGGER_NAME.equalsIgnoreCase(name)) {
        return root;
    }

    int i = 0;
    Logger logger = root;

    // check if the desired logger exists, if it does, return it
    // without further ado.
    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);
        }
        // move i left of the last point
        i = h + 1;
        synchronized (logger) {
            childLogger = logger.getChildByName(childName);
            if (childLogger == null) {
                childLogger = logger.createChildByName(childName);
                loggerCache.put(childName, childLogger);
                incSize();
            }
        }
        logger = childLogger;
        if (h == -1) {
            return childLogger;
        }
    }
}
複製程式碼

關於logback的原始碼可以參考這個系列的文章：logback原始碼系列文章

遇到過的坑

我自己在日誌這塊遇到的最多的坑就是日誌jar的依賴衝突；因為專案用到的很多框架或者三方依賴中可能自己都整合了日誌框架，有的時候我們自己的專案中也會有自己的一套日誌方案，所以就很大程度上導致了這種依賴衝突的發生。幸運的是，專案中關於日誌包的依賴衝突解決也是很容易排除的【idea和eclipse都很方便排查】

另外一個就是使用slf4j之後，同時引入了不同的框架實現；比如同時引入了log4j和logback。

從上面getLogger的方法中可以看到，在獲取Logger的時候都需要去先取得ILoggerFactory：

ILoggerFactory iLoggerFactory = getILoggerFactory();

public static ILoggerFactory getILoggerFactory() {
    if (INITIALIZATION_STATE == 0) {
        Class var0 = LoggerFactory.class;
        synchronized(LoggerFactory.class) {
            if (INITIALIZATION_STATE == 0) {
                INITIALIZATION_STATE = 1;
                //初始化
                performInitialization();
            }
        }
    }

    switch(INITIALIZATION_STATE) {
    case 1:
        return SUBST_FACTORY;
    case 2:
        throw new IllegalStateException("org.slf4j.LoggerFactory could not be successfully initialized. See also http://www.slf4j.org/codes.html#unsuccessfulInit");
    case 3:
        return StaticLoggerBinder.getSingleton().getLoggerFactory();
    case 4:
        return NOP_FALLBACK_FACTORY;
    default:
        throw new IllegalStateException("Unreachable code");
    }
}
複製程式碼

在getILoggerFactory中會通過performInitialization方法來做初始化判斷；而在performInitialization中又呼叫了bind方法，bind方法中的異常或者錯誤資訊列印很多情況下我們都會遇到：

private static final void bind() {
    String msg;
    try {
        Set<URL> staticLoggerBinderPathSet = null;
        if (!isAndroid()) {
            staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
            reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
        }

        StaticLoggerBinder.getSingleton();
        INITIALIZATION_STATE = 3;
        reportActualBinding(staticLoggerBinderPathSet);
        fixSubstituteLoggers();
        replayEvents();
        SUBST_FACTORY.clear();
    } catch (NoClassDefFoundError var2) {
        msg = var2.getMessage();
        if (!messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) {
            failedBinding(var2);
            throw var2;
        }

        INITIALIZATION_STATE = 4;
        Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\".");
        Util.report("Defaulting to no-operation (NOP) logger implementation");
        Util.report("See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.");
    } catch (NoSuchMethodError var3) {
        msg = var3.getMessage();
        if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) {
            INITIALIZATION_STATE = 2;
            Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding.");
            Util.report("Your binding is version 1.5.5 or earlier.");
            Util.report("Upgrade your binding to version 1.6.x.");
        }

        throw var3;
    } catch (Exception var4) {
        failedBinding(var4);
        throw new IllegalStateException("Unexpected initialization failure", var4);
    }

}
複製程式碼

reportMultipleBindingAmbiguity方法用來提示多重繫結，並通過日誌告訴你具體是有那幾個繫結了。

Class path contains multiple SLF4J bindings.

reportActualBinding這個是繫結成功的時候，會通過日誌顯示具體繫結成功的是哪一個日誌框架

Actual binding is of type [XXXX]

關於StaticLoggerBinder

從下面這個異常說起：

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for
further details.
複製程式碼

這個問題是因為載入類檔案org.slf4j.impl.StaticLoggerBinder時失敗；為什麼呢？下面是官網對於這個原因的解釋：

This error is reported when the org.slf4j.impl.StaticLoggerBinder class could not be loaded into memory. This happens when no appropriate SLF4J binding could be found on the class path. Placing one (and only one) of slf4j-nop.jar, slf4j-simple.jar, slf4j-log4j12.jar, slf4j-jdk14.jar or logback-classic.jar on the class path should solve the problem.

這個錯誤發生的原因是StaticLoggerBinder類不能被載入到記憶體中。發生這種情況時,無法找到合適的SLF4J繫結類路徑。slf4j-nop放置一個(且只有一個)。slf4j-simple jar。slf4j-log4j12 jar。slf4j-jdk14 jar。jar或logback-classic。jar的類路徑應該解決這個問題。

也就是說沒有找到具體的日誌框架來繫結實現。所以我們需要引入一個具體的日誌實現jar就可以了。

網上看到的一片關於slf4j的文章，感覺挺好的，分享給大家：slf4j原始碼剖析

新的環境還在適應中，部落格的更新頻次也直線下降，慢慢學，慢慢寫吧。也希望小夥伴們多多見諒！

相關文章