Spring周邊：日誌——上

• 2019 年 11 月 15 日
• 筆記

有日誌么？

日誌有價值么？

日誌框架了解么？

「日誌」這個詞最早見於航海領域，是記錄航行主要情況的載體文件，內容包括操作指令、氣象、潮流、航向、航速、旅客、貨物等，是處理海事糾紛或者海難的原始依據之一。爾後延伸到航空領域，黑匣子就是一個重要的航空日誌載體，調查空難原因時第一反應是找到黑匣子，並通過解析其中的日誌信息來還原空難的事實真相 碼出高效：Java開發手冊

本期內容提要

JUL、log4j1、log4j2、logback 基礎

1. JUL（Java Util Logging）

JUL（Java Util Logging），也稱做 JDK Logging，是自 JDK 1.4 以來自帶的日誌記錄技術。

1.1. 基礎

用JDK Logging 記日誌的例子： package webj2ee; import java.io.IOException;import java.util.logging.*; public class JdkLoggingDemo { public static void main(String[] args) throws IOException { // Handler – ConsoleHander ConsoleHandler consoleHandler = new ConsoleHandler(); consoleHandler.setLevel(Level.ALL); consoleHandler.setFormatter(new Formatter() { // Formatter @Override public String format(LogRecord record) { return "[CONSOLE-1]"+record.getMessage()+"n"; } }); // Handler – FileHandler FileHandler fileHandler = new FileHandler("filelog.log"); fileHandler.setLevel(Level.ALL); fileHandler.setFormatter(new Formatter() { // Formatter @Override public String format(LogRecord record) { return "[FILE-1]"+record.getMessage()+"n"; } }); // Logger Logger logger = Logger.getLogger(JdkLoggingDemo.class.getName()); logger.addHandler(consoleHandler); logger.addHandler(fileHandler); logger.setUseParentHandlers(false); // 避免將日誌打到父Logger上 logger.setLevel(Level.ALL); logger.setFilter(new Filter() { @Override public boolean isLoggable(LogRecord record) { return true; } }); // 7 個日誌級別 logger.finest("finest msg!"); logger.finer("finer msg!"); logger.fine("fine msg!"); logger.config("confg msg!"); logger.info("info msg!"); logger.warning("warning msg!"); logger.severe("severe msg!"); // 還能記錄異常 try{ throw new NullPointerException("exception!"); }catch(NullPointerException ex){ logger.log(Level.SEVERE, ex.getMessage(), ex); } }}

關鍵點：

• LogManager：整個 JVM 中只有一個 LogManager。管理着一堆有繼承關係的 Logger。管理着一堆key-value控制參數，用於對 Handlers 等其他對象進行配置。
• Logger：日誌記錄的外部操作界面，是 JDK Logging 模塊的代言人。而且 Logger 是有層次關係的。【一個 LogManager 管理着多個 Logger】
• Handler：用於控制日誌輸出方式。例如：JDK 自帶的 ConsoleHandler、FileHandler；【一個 Logger 可以對應多個 Formatter】
• Formatter：用于格式化即將輸出的日誌。例如：JDK自帶的 SimpleFormatter、XMLFormatter；【一個 Handler 對應一個 Formatter】

• Log Level：日誌級別，JDK Logging 預定義了 7 個級別。
• JDK Logging 的默認配置文件為：$JAVA_HOME/jre/lib/logging.properties，可通過修改系統屬性【java.util.logging.config.file】，加載自己的配置文件；
• JDK Logging 的默認 Logger 管理器為 java.util.logging.LogManager，可通過修改系統屬性【 java.util.logging.manager 】使用自定義的管理器。

1.2. logging.properties 配置

• .level 屬性：全局配置，用於配置默認的全局日誌級別；

• handlers 屬性：全局配置，用於配置 root Logger 的 Handler，是用空格或逗號分隔的 Handler 類名；

• <logger>.handlers 屬性：用於配置指定 logger 的 Handler，也是用空格或逗號分隔的 Handler 類名；

• <logger>.useParentHandlers 屬性：在默認情況下，日誌記錄器會將日誌發送到自己的處理器和父處理器。如果將<logger>.useParentHandlers配置為false，則不會將日誌發送到父處理器。

1.3. 基本原理

• Logger.getLogger(xxx) 實際是通過全局的 Logger 管理器 LogManager 獲取的。

• 全局只有一個 LogManager，默認採用 java.util.logging.LogManager 實現類，也可以通過系統屬性 java.util.logging.manager 使用自定義的 LogManager 實現類。

• logger.log(xxx)、logger.info(xxx)、logger.server(xxx) 等控制日誌輸出的方法，實際是將日誌消息委託給 logger 的各種 Handler 輸出。而且默認會將日誌委託給父 logger 輸出（可通過 useParentHandlers 屬性控制）。

• Handler 負責最終輸出，通過 Formatter 控制輸出格式，通過 Level 控制日誌級別，通過 Filter 自定義日誌過濾規則。

• SimpleFormatter 則直接使用 JDK 的 Formatter 技術完成簡單格式化（參考：Spring周邊：Formatter（字符串格式化））。

2. Log4j 1.x

注意：Apache 官方於 2015.8.5 宣布 Log4j 1.x 項目生命周期結束，並建議用戶升級到 Log4j 2（Log4j2 更快、更可靠、使用更簡單）。

2.1. POM

<!-- https://mvnrepository.com/artifact/log4j/log4j --><dependency>  <groupId>log4j</groupId>  <artifactId>log4j</artifactId>  <version>1.2.17</version></dependency>

註：log4j-1.2.17 是 log4j 1.x 的最後一個官方發佈版本。

2.2. Loggers、Appenders、Layouts 概述

Log4j 有 3 類主要組件：loggers、appenders、layouts。

2.3. Loggers

2.3.1 Loggers 的層次結構

• Loggers 是命名的實體；
• Loggers 的命名區分大小寫；
• Loggers 是具備層次關係的；

A logger is said to be an ancestor of another logger if its name followed by a dot is a prefix of the descendant logger name. A logger is said to be a parent of a child logger if there are no ancestors between itself and the descendant logger. Named Hierarchy

例如：

• 命名為「com.foo」的 Logger 是「com.foo.Bar」的父 Logger：
• 命名為「java」的 Logger 是「java.util」的父 Logger、是「java.util.Vector」的祖先 Logger；
• 通過 Logger.getLogger(String name) 方法獲取 logger；
• 注1：root logger 始終存在，且不能通過 name 獲取，只能通過 Logger.getRootLogger() 方法獲取；

Logger 的基本接口，如下所示：

package org.apache.log4j;  public class Logger {    // Creation & retrieval methods:    public static Logger getRootLogger();    public static Logger getLogger(String name);      // printing methods:    public void trace(Object message);    public void debug(Object message);    public void info(Object message);    public void warn(Object message);    public void error(Object message);    public void fatal(Object message);      // generic printing method:    public void log(Level l, Object message);}

2.3.2 Logger 的 LEVEL

Logger 可以設置 level：TRACE、DEBUG、INFO、WARN、ERROR、FATAL；

• DEBUG < INFO < WARN < ERROR < FATAL
• 如果一個 logger 沒有設置 level，則它繼承距離他最近的、設置 level的祖先 logger 的 level
• root logger 始終需要顯式指明 level。

示例：

圖：Logger LEVEL 的繼承關係

2.3.3 日誌記錄請求（logging request）的LEVEL

• Logging requests are made by invoking one of the printing methods of a logger instance. These printing methods are debug, info, warn, error, fatal and log.
• A logging request is said to be enabled if its level is higher than or equal to the level of its logger. Otherwise, the request is said to be disabled. A logger without an assigned level will inherit one from the hierarchy.

A log request of level p in a logger with (either assigned or inherited, whichever is appropriate) level q, is enabled if p >= q. Basic Selection Rule

例子：

package webj2ee;  import org.apache.log4j.Level;import org.apache.log4j.Logger;  public class Log4jDemo {    public static void main(String[] args) {        // get a logger instance named "com.foo"        Logger logger = Logger.getLogger("com.foo");          // Now set its level. Normally you do not need to set the        // level of a logger programmatically. This is usually done        // in configuration files.        logger.setLevel(Level.INFO);          Logger barlogger = Logger.getLogger("com.foo.Bar");          // This request is enabled, because WARN >= INFO.        logger.warn("Low fuel level.");          // This request is disabled, because DEBUG < INFO.        logger.debug("Starting search for nearest gas station.");          // The logger instance barlogger, named "com.foo.Bar",        // will inherit its level from the logger named        // "com.foo" Thus, the following request is enabled        // because INFO >= INFO.        barlogger.info("Located nearest gas station.");          // This request is disabled, because DEBUG < INFO.        barlogger.debug("Exiting gas station search");    }}

2.3.4 Logger 的單例特性

Calling the getLogger method with the same name will always return a reference to the exact same logger object.

Logger x = Logger.getLogger("wombat");Logger y = Logger.getLogger("wombat");assert x == y;

進階示例：

package webj2ee;  import org.apache.log4j.BasicConfigurator;import org.apache.log4j.Level;import org.apache.log4j.Logger;  import java.util.concurrent.Callable;import java.util.concurrent.FutureTask;  public class Log4jDemo {    public static void main(String[] args) throws InterruptedException {        BasicConfigurator.configure();          // get a logger instance named "com.foo"        Logger logger = Logger.getLogger("com.foo");          // Now set its level. Normally you do not need to set the        // level of a logger programmatically. This is usually done        // in configuration files.        logger.setLevel(Level.INFO);          new Thread(new FutureTask<String>(new Callable<String>() {            @Override            public String call() throws Exception {                try {                    Thread.sleep(2000);                } catch (InterruptedException e) {                    e.printStackTrace();                }                Logger logger = Logger.getLogger("com.foo");                logger.setLevel(Level.DEBUG);                return null;            }        })).start();          int i=0;        while (i++ < 3){            Logger barlogger = Logger.getLogger("com.foo.Bar");              // This request is enabled, because WARN >= INFO.            logger.warn(">>>>>>Low fuel level.");              // This request is disabled, because DEBUG < INFO.            logger.debug("Starting search for nearest gas station.");              // The logger instance barlogger, named "com.foo.Bar",            // will inherit its level from the logger named            // "com.foo" Thus, the following request is enabled            // because INFO >= INFO.            barlogger.info("Located nearest gas station.");              // This request is disabled, because DEBUG < INFO.            barlogger.debug("Exiting gas station search");              Thread.sleep(1000);        }    }}

2.4. Appenders

• 日誌的一個輸出目的地，就是 appender。
• Logger 可以有多個 appender；
• Each enabled logging request for a given logger will be forwarded to all the appenders in that logger as well as the appenders higher in the hierarchy.
• 可通過配置 logger 的 additivity 標記打破這一累加特性；

The output of a log statement of logger C will go to all the appenders in C and its ancestors. This is the meaning of the term "appender additivity". However, if an ancestor of logger C, say P, has the additivity flag set to false, then C's output will be directed to all the appenders in C and its ancestors upto and including P but not the appenders in any of the ancestors of P. Loggers have their additivity flag set to true by default. —— Appender Additivity

圖：appender additivity 特性圖

2.5. Layouts

Appenders 用於控制日誌的輸出目的地，Layouts 則可以附加到 Appender上控制日誌輸出格式。

2.6. 配置 Log4j

• 可通過編程形式配置 log4j；
• 可通過配置文件配置 log4j（xml、properties）；

2.6.1 BasicConfigurator.configure()

BasicConfigurator.configure() 是 log4j 自帶的、最基礎的配置模塊，它會給 root logger 添加一個 ConsoleAppender。

示例：

package webj2ee;  import org.apache.log4j.BasicConfigurator;import org.apache.log4j.Logger;  public class Log4jDemo {    public static void main(String[] args) {        BasicConfigurator.configure();          Logger logger = Logger.getLogger(Log4jDemo.class);        logger.info("log some message!");    }}

2.6.2 PropertyConfigurator.configure()

PropertyConfigurator.configure() 可以從文件、I/O、URL、Properties 中讀取對 log4j 的配置：

示例：

package webj2ee;  import org.apache.log4j.Logger;import org.apache.log4j.PropertyConfigurator;  import java.util.Properties;  public class Log4jDemo {    public static void main(String[] args) {        // Log4j Configuration: Properties        Properties log4jprops = new Properties();        log4jprops.setProperty("log4j.rootLogger", "DEBUG, A1");        log4jprops.setProperty("log4j.appender.A1", "org.apache.log4j.ConsoleAppender");        log4jprops.setProperty("log4j.appender.A1.layout", "org.apache.log4j.PatternLayout");        log4jprops.setProperty("log4j.appender.A1.layout.ConversionPattern", "%-4r [%t] %-5p %c %x - %m%n");          // Load Log4j Configuration:        PropertyConfigurator.configure(log4jprops);          // do logging        Logger logger = Logger.getLogger(Log4jDemo.class);        logger.info("log some message!");    }}

2.6.4 Log4j 的默認初始化套路

3. Log4j2

package webj2ee;  import org.apache.logging.log4j.LogManager;import org.apache.logging.log4j.Logger;  public class Log4j2Demo {    public static void main(String[] args) {        // root logger        Logger logger = LogManager.getRootLogger();                // 同一個 name，同一個 logger        Logger x = LogManager.getLogger("wombat");        Logger y = LogManager.getLogger("wombat");        System.out.println(x == y);                // 同樣有 Logger 分級        // 同樣有 logging request 分級        // 同樣有 additivity 控制策略    }}

4. Logback

4.1. Logback 基本構成

Logback 分3個模塊：logback-core, logback-classic，logback-access。

• logback-core：是其他兩個模塊的基礎模塊；
• logback-classic：可理解為升級版的 log4j，並且實現了slfj接口；
• logback-access：與 Servlet 容器整合，提供基於 HTTP-access 的日誌功能；

備註：Logback-classic module requires the presence of slf4j-api.jar and logback-core.jar in addition to logback-classic.jar on the classpath.

maven 依賴：

<dependency>  <groupId>ch.qos.logback</groupId>  <artifactId>logback-core</artifactId>  <version>1.2.3</version></dependency><dependency>  <groupId>ch.qos.logback</groupId>  <artifactId>logback-classic</artifactId>  <version>1.2.3</version></dependency><dependency>  <groupId>org.slf4j</groupId>  <artifactId>slf4j-api</artifactId>  <version>1.7.29</version></dependency>

示例：

package webj2ee;  import org.slf4j.Logger;import org.slf4j.LoggerFactory;  public class LogbackDemo {    public static void main(String[] args) {        Logger logger = LoggerFactory.getLogger(LogbackDemo.class);        logger.debug("Hello world!");    }}

4.2. Logger、Appenders、Layouts

• Logback 核心由 Logger、Appender、Layout 構成；
• Logger 隸屬於 logback-classic 模塊；
• Appender、Layout 隸屬於 logback-core 模塊；

4.2.1 LoggerContext、Logger 繼承關係

• 與 Log4j 類似，也通過 name 區分繼承關係；
• 與 Log4j 不同，Logger 是藉助 LogContext 體現繼承關係；
• 與 Log4j 不同，通過 SLFJ 的 LoggerFactory.getLogger() 獲取 Logger；
• 與 Log4j 類似，logging request 也分級別；
• 與 Log4j 類似，同一個 name，同一個 Logger；
• 與 Log4j 類似，也有 additivity 控制；

圖：logger level 策略示意

圖：logging request level 策略示意

圖：additivity 策略示意

例1：logging request level 與 logger level 關係；

package webj2ee;  import org.slf4j.Logger;import org.slf4j.LoggerFactory;  public class LogbackDemo {    public static void main(String[] args) {        Logger x = LoggerFactory.getLogger("wombat");        Logger y = LoggerFactory.getLogger("wombat");        System.out.println(x == y);    }}

4.3. logback 配置

4.3.1 默認配置步驟

4.3.2 經典配置

<configuration>  <appender name="FILE" class="ch.qos.logback.core.FileAppender">    <file>foo.log</file>    <encoder>      <pattern>%date %level [%thread] %logger{10} [%file : %line] %msg%n</pattern>    </encoder>  </appender>    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">    <encoder>      <pattern>%msg%n</pattern>    </encoder>  </appender>    <logger name="chapters.configuration.Foo" additivity="false">    <appender-ref ref="FILE" />  </logger>    <root level="debug">    <appender-ref ref="STDOUT" />  </root></configuration>

5. 怎麼合理記錄日誌？

5.1. 正確區分日誌級別

• debug：完整詳細的記錄流程的關鍵路徑. 應該用於開發人員比較感興趣的跟蹤和調試信息, 生產環境中正常都不會打開debug狀態
• info：應該簡潔明確讓管理員確認狀態。記錄相當重要的，對於最終用戶和系統管理員有意義的消息。關鍵系統參數的回顯、後台服務的初始化狀態、需要系統管理員知會確認的關鍵信息都需要使用INFO級別
• warn：能清楚的告知所有人發生了什麼情況.能引起人的重視，指示潛在問題，但不一定需要處理。
• error：系統出現了異常或不期望出現的問題，希望及時得到關注的處理。

5.2. 最佳實踐

• 應用中不可直接使用日誌系統（Log4j、Logback）中的API，而應該依賴使用日誌框架 SLF4J 的 API。
• 禁止使用 System.out 或 System.error。
• 盡量使用英文來描述日誌錯誤信息（避免因為字符集問題造成的日誌亂碼）。
• 謹慎地記錄日誌。記錄日誌時請思考：這些日誌真的有人看嗎？看到這條日誌你能做什麼？能不能給問題排查帶來好處？
• 異常信息應該包括兩類信息：異常堆棧信息和案發現場信息（例如：盡量通過異常的日誌能還原當時的情景，比如當時受影響的是哪個用戶、傳入的變量是什麼、處理哪些核心數據引發的異常等等）。

正例：logger.error(各類參數或對象toString()+"_" + e.getMessage(), e);

• 在日誌輸出時，字符串變量之間的拼接使用佔位符的方式。

正例：logger.debug("Processing trade with id: {} and symbol: {}", id, symbol);

• 對於 trace/debug/info 級別的日誌輸出，必須進行日誌級別的開關判斷。

if (logger.isDebugEnabled()) {    logger.debug("Processing trade with id: {} and symbol: {}", id, symbol);}

5.3. 案例分析

2.3.1 例1

改造前：

改造後：

參考：

《碼出高效：Java 開發手冊》 《Java 開發手冊 1.5.0》 JDK Logging 深入分析： https://blog.csdn.net/qingkangxu/article/details/7514770 jdk-logging、log4j、logback日誌介紹及原理： https://my.oschina.net/pingpangkuangmo/blog/406618 優雅的使用slf4j： https://www.jianshu.com/p/7b5860be190f log4j1.2： http://logging.apache.org/log4j/1.2/ Apache™ Logging Services™ Project Announces Log4j™ 1 End-Of-Life; Recommends Upgrade to Log4j 2： https://blogs.apache.org/foundation/entry/apache_logging_services_project_announces 《The complete log4j manual》 logback： http://logback.qos.ch/index.html