Spring周边：日志——上

有日志么？

日志有价值么？

日志框架了解么？

“日志”这个词最早见于航海领域，是记录航行主要情况的载体文件，内容包括操作指令、气象、潮流、航向、航速、旅客、货物等，是处理海事纠纷或者海难的原始依据之一。尔后延伸到航空领域，黑匣子就是一个重要的航空日志载体，调查空难原因时第一反应是找到黑匣子，并通过解析其中的日志信息来还原空难的事实真相 码出高效：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