如何优雅地记录日志？

如何优雅地记录日志？在开发过程中，我们需要输出一些日志，看到过一些离谱的同事的离谱的操作：

没错，简单粗暴，但是阿里规范中说到

【强制】生产环境禁止直接使用System.out 或System.err 输出日志或使用 e.printStackTrace()打印异常堆栈。

说明：标准日志输出与标准错误输出文件每次Jboss重启时才滚动，如果大量输出送往这两个文件，容易 造成文件大小超过操作系统大小限制。

但是还是大多数同事不这样做的，而在开发过程中我们一般是用日志框架来记录日志，例如日志框架（SLF4J）加 日志系统（Log4j、Logback）来记录日志，SLF4J 是一个抽象层，或者说是一个日志接口（API），它并不直接提供日志实现。Log4j 和 Logback 是具体实现日志功能的工具，它们提供了完整的日志记录能力。

就像阿里规范中说的：

【强制】应用中不可直接使用日志系统（Log4j、Logback）中的 API，而应依赖使用日志框架（SLF4J、JCL–Jakarta Commons Logging）中的 API，使用门面模式的日志框架，有利于维护和各个类的日志处理方式统一。

也就是说SLF4J 自己不负责日志的具体实现，而是通过桥接器（Binding）将调用转发给实际的日志实现（例如 Logback 或 Log4j）。而我们平常用的lombok就是使用的Slf4j＋Logback 来实现的日志功能：

使用Slf4j

如果我们是springboot项目，直接在maven的pom文件里面导入两个jar包

        <!-- SLF4J API -->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.32</version> <!-- 使用最新的版本 -->
        </dependency>

        <!-- Logback Classic Module -->
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.2.6</version> <!-- 使用最新的版本 -->
        </dependency>

之后即可在代码中正常的使用日志记录了：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class DemoController {

    private static final Logger log = LoggerFactory.getLogger(DemoController.class);

    @GetMapping("/log")
    public String log() {
        log.trace("trace");
        log.debug("debug");
        log.info("info");
        log.warn("warn");
        log.error("error");
        return "nihao";
    }

}

但是，我们大名鼎鼎的lombok 里面已经集成了Slf4j + logback 使用起来也更优雅，直接导入一个jar包即可：

<dependency>
    <groupId>org.projectlombok</groupId>
    <artifactId>lombok</artifactId>
</dependency>

而在使用起来更简单，直接在类上面标注@Slf4j注解即可：

import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;


@RestController
@Slf4j
public class DemoController {


    @GetMapping("/log")
    public String log() {
        log.trace("trace");
        log.debug("debug");
        log.info("info");
        log.warn("warn");
        log.error("error");
        return "nihao";
    }

}

而不管用哪种方式，他们最后编译出来的代码都是一样的：

配置日志

日志级别

按照优先级从高到低排列

级别	描述	使用场景
ERROR	表示严重的错误或异常，通常需要立即处理。	系统运行过程中发生的错误，例如数据库连接失败、文件读取异常等。
WARN	表示潜在的问题或警告，可能会影响系统的正常运行，但不会导致系统崩溃。	非致命问题，例如使用了不推荐的 API、配置文件中缺少某些参数等。
INFO	表示重要的信息，通常是系统运行的关键步骤或状态变化。	系统启动、关闭、完成重要任务时的记录，或者业务流程中的关键点。
DEBUG	表示调试信息，用于开发和维护阶段，帮助开发者理解程序的运行过程。	方法调用、变量值、分支判断等详细信息，主要用于排查问题。
TRACE	表示最详细的追踪信息，通常用于跟踪程序执行的每一个步骤。	跟踪程序运行的每个细节，例如方法进入/退出、参数传递等，主要用于深度调试。

我们亲爱的slf4j默认开启的是info级别的，即只会打印 优先级别大于或等于info级别的日志，就像我们案例中 trace和 debug 就没有打印出来：

但是我们可以通过在配置文件yml加入以下的配置：

logging:
  level:
    root: trace

这样日志就能正常输出 trace 及其以上优先级别的日志了，但是需要注意的是系统会一直打印非常详细的日志，会影响系统性能的同时还会影响日志的查看，所以一般我们在开发过程中使用info及其以上的日志。

而另外一种方法就是在 resource 文件夹下面创建一个叫 logback.xml 的文件，里面内容为：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false">
    <root level="INFO">
        <appender-ref ref="console"/>
    </root>
</configuration>

logback.xml 是 Logback 日志框架的配置文件，它用于定义日志的记录策略、格式、级别以及其他相关配置。

是Logback配置文件的根元素。
debug=“false” 表示不启用Logback内部的调试信息。
scan=“false” 表示不自动扫描和重新加载配置文件。

Logback 会自动查找 src/main/resources/logback.xml 下的配置文件，一旦找到合适的配置文件，Logback 会解析该文件以获取配置信息。这包括日志记录器的配置（如日志级别、输出目标等）。所有我们可以不用在yml文件中定义文件级别，在这里定义也可。

自定义输出文件

大家都知道我们的日志文件默认输出到IDEA控制台，如果使用jave - jar 命令行来运行则会输出到命令行里面，这在我们本地开发还好，但是如果线上使用jar包发版呢？

除了使用 java -jar app.jar > output.txt 外，我们还可以使用logback的自定义日志文件的功能，就像这样：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false">
    <property name="log.path" value="logs/demo"/>
    <!-- Log file debug output -->
    <appender name="debug" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/debug.log</file>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="debug"/>
    </root>
</configuration>

这样我们的日志就会输出到我们的debug.log文件里面了：

同时输出

自定义输出文件那样写是可以，但是我们发现我们的控制台居然没有输出日志了

那我既要输出到日志文件又要输出到控制台怎么办呢？没事儿，logback都想到了:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false">
    <property name="log.path" value="logs/demo"/>
    <property name="CONSOLE_LOG_PATTERN"
              value="${CONSOLE_LOG_PATTERN:-%d{yyyy-MM-dd HH:mm:ss} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%15.15t] %-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
  
    <!-- Console log output -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <!-- Log file debug output -->
    <appender name="debug" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/debug.log</file>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
    </appender>


    <root level="INFO">
        <appender-ref ref="console"/>
        <appender-ref ref="debug"/>
    </root>
</configuration>

通过两个 标签，即可输出到 对应的 标签里面。

自定义输出格式

一般我们的日志目的是什么时间发生了什么事情，哪里发生的，时间戳、日志级别、进程ID、线程名、日志记录器名称、日志消息以及异常信息等。

但是我们可以在日志输出的时候改一些东西，例如我们可以把毫秒去掉**（yyyy-MM-dd HH:mm:ss.SSS）**SSS(毫秒）：

    <property name="CONSOLE_LOG_PATTERN"
              value="${CONSOLE_LOG_PATTERN:-%d{yyyy-MM-dd HH:mm:ss} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%15.15t] %-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>


    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>

这样我们输出的日志就没有毫秒了，还可以添加很多的东西，例如：

1. 时间相关

   • %d{yyyy-MM-dd HH:mm:ss.SSS}：输出日期和时间，精确到毫秒。
   • %d{ISO8601}：输出 ISO8601 格式的时间。

2. 日志级别

   • %level 或 %p：输出日志级别（如 INFO、DEBUG、ERROR 等）。
   • %-5level：输出日志级别，并左对齐，宽度为 5 个字符。

3. 线程信息

   • %thread：输出当前线程的名称。
   • %t：输出当前线程的简短名称。

4. 日志记录器

   • %logger：输出日志记录器的名称。
   • %-40.40logger{39}：输出日志记录器名称，左对齐，最大长度为 40 个字符，超过部分截断。

5. 消息内容

   • %msg 或 %m：输出日志消息内容。
   • %n：输出换行符。

6. 异常信息

   • %ex：输出异常堆栈信息。
   • %wEx：输出格式化的异常堆栈信息。

7. 其他

   • %M：输出调用日志的方法名称。
   • %L：输出调用日志的代码行号。
   • %file：输出调用日志的文件名。
   • %class：输出调用日志的类名。

而我们经常使用一些组合示例：

1. 简单格式

   %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n
   

   输出示例：

   2023-10-05 14:30:00 [main] INFO  com.example.MyClass - This is a log message.
   

2. 包含文件和行号

   %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} (%file:%line) - %msg%n
   

   输出示例：

   2023-10-05 14:30:00 [main] INFO  com.example.MyClass (MyClass.java:42) - This is a log message.
   

3. 包含异常信息

   %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n%wEx
   

   输出示例：

   2023-10-05 14:30:00 [main] ERROR com.example.MyClass - An error occurred.
   java.lang.NullPointerException: null
       at com.example.MyClass.method(MyClass.java:42)
   

而作者示例中是包含以下含义：

${CONSOLE_LOG_PATTERN:-%d{yyyy-MM-dd HH:mm:ss.SSS} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%15.15t] %-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}

1. 时间戳

   • %d{yyyy-MM-dd HH:mm:ss.SSS}：输出当前时间，格式为 年-月-日 时:分:秒.毫秒。

2. 日志级别

   • ${LOG_LEVEL_PATTERN:-%5p}：输出日志级别（如 INFO、DEBUG 等），默认格式为 %5p，表示右对齐，宽度为 5 个字符。

3. 进程 ID

   • ${PID:- }：输出当前进程 ID，如果未定义则输出空格。

4. 分隔符

   • ---：固定的分隔符，用于分隔不同字段。

5. 线程名称

   • [%15.15t]：输出当前线程名称，宽度为 15 个字符，超过部分截断。

6. 日志记录器名称

   • %-40.40logger{39}：输出日志记录器名称，左对齐，宽度为 40 个字符，超过部分截断。

7. 消息内容

   • %m：输出日志消息内容。
   • %n：输出换行符。

8. 异常信息

   • ${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}：输出异常堆栈信息，默认使用 %wEx 格式化异常信息。

彩色日志

配置好上面的内容之后，我们发现IDEA的控制台是没有日志颜色的，例如每个日志级别显示的数据都是一样的，这样很不方便我们去查看日志：

但是我们加上这样的一段配置之后，神奇的事情发生了。

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false">
    <property name="log.path" value="logs/demo"/>
    <!-- 彩色日志格式 -->
    <property name="CONSOLE_LOG_PATTERN"
              value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <!-- 彩色日志依赖的渲染类 -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
    <conversionRule conversionWord="wex"
                    converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter"/>
    <conversionRule conversionWord="wEx"
                    converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter"/>
    <!-- Console log output -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="console"/>
    </root>
</configuration>

1. 时间戳

   • %clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint}：输出当前时间，格式为 年-月-日 时:分:秒.毫秒，并使用 faint（浅色）渲染。

2. 日志级别

   • %clr(${LOG_LEVEL_PATTERN:-%5p})：输出日志级别（如 INFO、DEBUG 等），默认格式为 %5p（右对齐，宽度为 5 个字符），并应用默认颜色渲染。

3. 进程 ID

   • %clr(${PID:- }){magenta}：输出当前进程 ID，如果未定义则输出空格，并使用 magenta（洋红色）渲染。

4. 分隔符

   • %clr(---){faint}：固定的分隔符 ---，并使用 faint（浅色）渲染。

5. 线程名称

   • %clr([%15.15t]){faint}：输出当前线程名称，宽度为 15 个字符，超过部分截断，并使用 faint（浅色）渲染。

6. 日志记录器名称

   • %clr(%-40.40logger{39}){cyan}：输出日志记录器名称，左对齐，宽度为 40 个字符，超过部分截断，并使用 cyan（青色）渲染。

7. 消息内容

   • %m：输出日志消息内容。
   • %n：输出换行符。

8. 异常信息

   • ${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}：输出异常堆栈信息，默认使用 %wEx 格式化异常信息。

通过这样的设置之后，IDEA的输出变得有颜色了，这样更方便我们查看error以及其他级别的日志了：

根据日志级别输出不同的文件

那么有这么一个背景：我的debug.log 文件想记录全部的日志，但是为了排查问题我们需要有一个专门记录 ERROR 级别的日志，所以我们可以在 标签再追加一个日志：

   
<!-- Log file error output -->
    <appender name="error" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/error.log</file>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

	<root level="INFO">
        <appender-ref ref="console"/>
        <appender-ref ref="error"/>
        <appender-ref ref="debug"/>
    </root>

这里我们在新的appender里面使用 标签过滤掉ERROR 级别的日志，这样，我们的error日志则会再追加一份到 error.log日志里面去了：

滚动存储日志

大家都知道，如果生产期间所有的日志都输出到一个日志文件中，那么文件的大小想都不敢想，那么我们就需要滚动存储，即分日期和文件大小去存储日志，不仅仅减少了我们日志文件的大小，还可以方便开发在追查问题的时候直接查看对应的日志文件即可，加上前面我们的error.log日志，查找bug产生的原因的效率就事半功倍了。

那么logback的强大之处也在与，只要几行的配置，即可实现我们滚动存储日志的这个需求：

      <!-- Log file debug output -->
    <appender name="debug" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/debug.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/%d{yyyy-MM, aux}/debug.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxFileSize>50MB</maxFileSize>
            <maxHistory>180</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
    </appender>

滚动策略（Rolling Policy），用于控制日志文件的生成、归档和删除。

1. 滚动策略类

   • class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"：使用基于时间和文件大小的滚动策略，即日志文件会根据时间和文件大小进行滚动。

2. 文件名模式

   • <fileNamePattern>${log.path}/%d{yyyy-MM, aux}/debug.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>：定义日志文件的命名规则：
     • ${log.path}：日志文件的存储路径。
     • %d{yyyy-MM, aux}：按年月创建子目录。
     • %d{yyyy-MM-dd}：按日期命名日志文件。
     • %i：当日志文件超过指定大小时，添加递增序号。
     • .gz：将日志文件压缩为 .gz 格式。

3. 最大文件大小

   • <maxFileSize>50MB</maxFileSize>：单个日志文件的最大大小为 50MB，超过后会自动创建新文件。

4. 最大历史文件数

   • <maxHistory>180</maxHistory>：最多保留 180 天的日志文件，超过后会自动删除旧文件。

屏蔽其他日志

有时候我们有很多不要的数据，例如nacos的心跳检测啦，定时器框架的日志啦，这些我们不需要的都可以屏蔽

    <!--nacos 心跳 INFO 屏蔽-->
    <logger name="com.alibaba.nacos" level="OFF">
        <appender-ref ref="error"/>
    </logger>

    <logger name="com.xxl.job.core" level="OFF">
        <appender-ref ref="error"/>
        <appender-ref ref="debug"/>
    </logger>

将日志级别设置为OFF意味着完全关闭该日志记录器的日志输出，即不会记录任何日志信息。OFF是Logback日志框架中的一个特殊级别，表示禁用日志输出，它不属于常见的日志级别（如DEBUG、INFO等），而是用于完全屏蔽日志。

至此，SLF4J 和 Logback 让我们记录日志变得更简单、更高效。但别忘了，日志不只是调试工具，它是系统的“记忆”和“眼睛”。清晰的日志能帮我们快速定位问题，优化性能，甚至预测风险。在复杂的分布式系统中，日志更是追踪问题的必备武器。

我们作为开发者，一定要养成良好的日志习惯，不仅让自己省心，也让团队协作更顺畅。记住，好日志 = 少麻烦，那么文章的最后给大家列出一份文章中完整的 logback.xml配置文件，方便大家一键复制：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false" scan="false">
    <property name="log.path" value="logs/demo"/>
    <!-- 彩色日志格式 -->
    <property name="CONSOLE_LOG_PATTERN"
              value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <!-- 彩色日志依赖的渲染类 -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
    <conversionRule conversionWord="wex"
                    converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter"/>
    <conversionRule conversionWord="wEx"
                    converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter"/>
    <!-- Console log output -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <!-- Log file debug output -->
    <appender name="debug" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/debug.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/%d{yyyy-MM, aux}/debug.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxFileSize>50MB</maxFileSize>
            <maxHistory>180</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- Log file error output -->
    <appender name="error" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/error.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/%d{yyyy-MM}/error.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxFileSize>50MB</maxFileSize>
            <maxHistory>180</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

    <!--nacos 心跳 INFO 屏蔽-->
    <logger name="com.alibaba.nacos" level="OFF">
        <appender-ref ref="error"/>
    </logger>

    <logger name="com.xxl.job.core" level="OFF">
        <appender-ref ref="error"/>
        <appender-ref ref="debug"/>
    </logger>

    <root level="INFO">
        <appender-ref ref="console"/>
        <appender-ref ref="error"/>
        <appender-ref ref="debug"/>
    </root>
</configuration>