tags: springboot logback log

一句话概括：logback 在实现了基本的日志输出到文件功能后，在企业实践中，还会有其它的进阶需求，本文对logback的进阶使用进行描述。

1.引言

上一篇文章《springboot+logback 日志输出企业实践（上）》对 logback 的使用及配置进行描述，并实现按日志级别输出到独立文件功能。但在企业实践中，还会有其它的需求，如需要在多环境下使用不同日志级别，日志输出性能低怎么处理，还有分布式系统如何追踪请求日志等等，对于这些需求，logback 有提供相应的功能，本文将对这几种需求的实现进行讲解。具体有如下内容：

• 使用异步输出日志提高性能
• logback 在多环境下选择日志级别配置
• 使用 MDC 在分布式系统中追踪请求

如需看源码，本文示例工程地址：https://github.com/mianshenglee/my-example/tree/master/springboot-logback-demo

2. 输出 logback 状态数据

logback 官方文档指出，强烈建议启用 logback 状态数据的输出，将会在很大程度上帮助我们诊断 logback 相关问题。通过这些状态数据，可以知道 logback 配置文件加载情况，配置中对应的 appender，logger的装载情况等。启用状态数据输出有两种方式：

• 在根元素( configuration ) 中设置属性debug="true"
• 添加元素( statusListener )，class 使用OnConsoleStatusListener。如下：

<!-- 输出logback的本身状态数据 -->
<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />

注意，二者选其一即可，此处的 debug 与配置文件中的日志级别没有关系，只用于表示输出状态数据。

本示例中，使用第二种方式（添加 statusListener 元素），添加后，输出内容如下所示：

3. logback 异步输出日志

3.1 异步输出配置

按之前的 logback 配置，日志输出到文件是同步输出的，即每次输出都会直接写IO到磁盘文件，从而产生阻塞，造成不必要的性能损耗。当然，对于一般的应用，影响不大，但对于高并发的应用，还是有必要对性能进行优化的。logback 提供了日志异步输出的 AsyncAppender。 异步输出日志的方式很简单，添加一个基于异步写日志的appender，并指向原先配置的appender即可 。见以下配置：

<!-- 异步输出 -->
<appender name="ASYNCDEBUG" class="ch.qos.logback.classic.AsyncAppender">
    <!-- 默认如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志，若要保留全部日志，设置为0 -->
    <discardingThreshold>0</discardingThreshold>
    <!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
    <queueSize>1024</queueSize>
    <!-- 添加附加的appender,最多只能添加一个 -->
    <appender-ref ref="DEBUGFILE"/>
    <includeCallerData>true</includeCallerData>
</appender>
//INFO 结构同上，略
//WARN 结构同上，略
//ERROR 结构同上，略
<!-- 异步输出关联到root -->
<root level="DEBUG">
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="ASYNCDEBUG" />
    ...//略
</root>

AsyncAppender 对应需要设置的参数主要有 :

3.2 异步输出原理

AsyncAppender 的实现方式是通过阻塞队列( BlockingQueue )来避免日志直接输出到文件，而是把日志事件输出到 BlockingQueue 中，然后启动一个新的worker线程，主线程不阻塞，worker线程则从队列中获取需要写的日志，异步输出到对应的位置。

4. springboot 多环境下 logback 配置

使用 springboot 进行应用开发，支持对多环境的配置支持，只需要按application-*.properties 格式添加配置文件，然后使用 spring.profiles.active 指定环境即可。同样，日志输出，一般在开发环境，使用 DEBUG 级别，以便以检查问题，而在生产环境，则只输出 ERROR 级别的日志。如下所示，profile定义开发环境为 dev ，生产环境为 prod：

<!-- 开发环境:debug级别-->
<springProfile name="dev">
    <root level="DEBUG">
        <appender-ref ref="STDOUT"/>
        ...//略
    </root>
</springProfile>

<!-- 生产环境:error级别-->
<springProfile name="prod">
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
        ...//略
    </root>
</springProfile>

上述配置是对 root 进行 设置（当然，其它元素也可以使用）。经过此设置后，则会根据 spring.profiles.active 而决定使用指定日志级别输出。

其实 logback 还支持使用 if 元素，使用 if-then-else 的形式，结合 condition 属性来实现条件处理。有兴趣的读者可以看官方文档说明 “Conditional processing of configuration files”

5. MDC 分布式应用追踪请求

使用springboot开发分布式应用，很多都微服务化，当请求过来，可能需要调用多个服务来完成请求动作。在查询日志时，特别是请求量大的情况下，日志多，很难找到对应请求的日志，造成定位异常难，日志难以追踪等问题。针对此类问题，logback 提供了 MDC （ Mapped Diagnostic Contexts 诊断上下文映射 ），MDC可以让开发人员可以在 诊断上下文 中放置信息，这些消息是内部使用了 ThreadLocal实现了线程与线程之间的数据隔离，管理每个线程的上下文信息 。而在日志输出时，可以通过标识符%X{key} 来输出MDC中的设置的内容。因此，在分布式应用在追踪请求时，实现思路如下：

1. web应用中，添加拦截器，在请求进入时，添加唯一id作为request-id，以标识此次请求。
2. 添加此 request-id 到MDC中
3. 若需要调用其它服务，把此request-id作为 header 参数
4. 在日志输出时，添加此request-id的输出作为标识
5. 请求结束后，清除此request-id

5.1 添加拦截器

5.1.1 拦截器实现

通过拦截器，实现在请求前添加request-id，并放到 MDC 中；请求完成后清除的动作。添加包 interceptor 存放拦截器类，类定义如下：

@Slf4j
@Component
public class RequestIdTraceInterceptor implements HandlerInterceptor {

    public static final String REQUEST_ID_KEY = "request-id";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        MDC.put(REQUEST_ID_KEY, getRequestId(request));
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
        //把requestId添加到响应头，以便其它应用使用
        response.addHeader(REQUEST_ID_KEY, MDC.get(REQUEST_ID_KEY));
        //请求完成，从MDC中移除requestId
        MDC.remove(REQUEST_ID_KEY);
    }
    
    public static String getRequestId(HttpServletRequest request) {...// 后面给出}
}

此拦截器主要覆盖 preHandle 及 afterCompletion 方法，分别请求前和请求完成后的处理。使用 MDC.put() 及 MDC.remove() 实现对MDC的写入及清除操作。

在获取 request-id 时，使用方法是 getRequestId()，如下所示：

public static String getRequestId(HttpServletRequest request) {
    String requestId;
    String parameterRequestId = request.getParameter(REQUEST_ID_KEY);
    String headerRequestId = request.getHeader(REQUEST_ID_KEY);
    // 根据请求参数或请求头判断是否有“request-id”，有则使用，无则创建
    if (parameterRequestId == null && headerRequestId == null) {
        log.debug("no request-id in request parameter or header");
        requestId = IdUtil.simpleUUID();
    } else {
        requestId = parameterRequestId != null ? parameterRequestId : headerRequestId;
    }

    return requestId;
}

根据请求参数或请求头判断是否有“request-id”，有则使用，无则创建，创建的request-id 为simpleUUID，以此作为唯一标识。

5.1.2 注册拦截器到web配置中

添加 config 包用于存放配置文件。继承 WebMvcConfigurer 实现 addInterceptors 来添加拦截器到 web 配置中：

@Configuration
public class WebAppConfig implements WebMvcConfigurer {
    @Autowired
    RequestIdTraceInterceptor requestIdTraceInterceptor;

    /**
     * 添加拦截器
     * @param registry
     */
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        //添加requestId
        registry.addInterceptor(requestIdTraceInterceptor);
    }
}

5.2 设置 MDC 日志输出

logback 的 MDC 输出是用%X{key} 来作标识符进行输出，因此，修改 logback-spring.xml 文件，在输出格式中添加 %X{request-id} 输出，如下：

<property name="log.pattern"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS} %5level [%10thread] [%X{request-id}] %40.40logger{40} [%10method,%line] : %msg%n"/>

至此，MDC处理完毕，启动应用，访问其中的某一个接口，输出如下（其中8e955ff61fa7494788f52891a4fdbc6a即可 request-id）：

注意，示例代码没有给出调用其它服务时的处理，当调用时，从 MDC 中获取 request-id ，然后把它作为 header参数，实现 request-id 的传递。这样查询日志时，根据此id来追踪就可以了。

6. 总结

本篇文章针对springboot应用开发中，如何更好的使用 logback 解决日志输出的相关问题，主要包括 loback 状态数据的输出，使用异步解决日志输出性能问题，配置多环境下的日志输出以及使用MDC解决分布式应用追踪请求。希望能对大家有帮助。

本文中使用的示例代码已放在我的github：https://github.com/mianshenglee/my-example/tree/master/springboot-logback-demo，有兴趣的同学可以pull代码，结合示例一起学习。

参考资料

• logback官网: ` http://logback.qos.ch `

• logback中文手册: ` http://www.logback.cn/ `

• logback github： https://github.com/qos-ch/logback

• 使用requestId在分布式系统追踪请求： https://juejin.im/post/5b51f85c5188251af91a7525

往期文章

• springboot+logback 日志输出企业实践（上）
• springboot+swagger 接口文档企业实践（下）
• springboot+swagger接口文档企业实践（上）
• 查阅了十几篇学习资源后，我总结了这份AI学习路径
• java应用监测(8)-阿里诊断工具arthas
• java应用监测(7)-在线动态诊断神器BTrace

关注我的公众号（搜索Mason技术记录），获取更多技术记录：