vlambda博客
学习文章列表

最近被公司派去北京出差，本以为是个轻松的差事，北京一周游~

但是没想到第一天就是九点半下班， 大意了~

好了，回到正题，今天来讲下最近调试项目的时候发现的一个 Logback 日志级别设置不生效的问题。

问题背景

事情是这样的，我们的项目是一个 SpringBoot 的工程的，其中日志框架使用的是 LogBack，配置文件如下所示：

<configuration scan="true" scanPeriod=" 5 seconds" debug="true">

    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%date [%thread] %-5level %logger{80} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="org.springframework" level="DEBUG"/>

    <root level="debug">
        <appender-ref ref="stdout"/>
    </root>

</configuration>

为了方便查看项目执行的 SQL，这里我把日志的级别调整成 DEBUG。

运行的项目，执行结果比较令人惊讶，日志仅仅输出了 INFO 日志，并没有输出 DEBUG 日志。

刚开始还以为 Logback 配置文件写的有问题，才导致这个问题。网上找了几个例子，对比了一下，这类的配置文件并没有什么问题。

于是进行一系列深度排查（令人头秃），最终终于找到了问题的原因。

问题原因

由于 Logback 的配置 debug=true,项目启动的时候，将会打印出 Logback  内部日志信息，日志如下：

从这个日志可以看到，Logback Root 已经设置为 DEBUG。

那为什么项目启动之后，DEBUG 就失效了？

不要急，接着往下看。

当 Spring 容器启动之后，Spring 内部将会发出一些列的 ApplicationEvent，然后这些将会被各类已经注册的  ApplicationListener监听。

由于这个项目是一个 SpringBoot 的工程，里面有一个  LoggingApplicationListener将会监听 ApplicationEnvironmentPreparedEvent，代码如下：

这里面的逻辑比较简单，获取系统配置的日志级别，levels 值如下：

可以看到这里 root 对应的值为 info，这里将会继续调用 Logback 的的方法设置日志级别，日志输出如下：

上面这些日志级别配置来自其实来自 SpringBoot 的配置文件 application.properties

总结

最后，总结一下，SpringBoot 项目，如果使用单独的 LogBack 配置文件，SpringBoot 的配置文件 application.properties 配置的 logging.level.root 将会覆盖的 Logback 配置文件中的 root 的配置：

<root level="debug">
    <appender-ref ref="stdout"/>
</root>

问题看起来是那么简单，排查的过程真的是令人头秃。