动态日志级别：小功能，大用处

⚠️本文为掘金社区首发签约文章，未获受权禁止转载java

Log4j，Log4j2，Logback是当下主流的日志框架，Slf4j则是新一代的日志框架接口，其中Logback直接实现了Slf4j的接口，同时它也是SpringBoot的默认日志框架。程序员

但从性能以及工程的角度上来看，Log4j2是事实标准，本文也是基于Log4j2来撰写的。apache

为何须要动态日志级别

关于Log4j2的名词小知识：markdown

配置方式：工业级项目通常都采用XML的配置方式

同步/异步：Log4j2支持同步/异步日志两种方式，如无特殊的场景须要，建议采用高性能的异步方式

Logger：Logger节点是用来单独指定日志的表现形式配置项，包括但不限于：日志级别、关联Appender、Name属性等

Appender：Appender一般只负责将事件数据写入目标目标目标，由Logger触发指定的Appender执行。

做为一个合格的程序员，你们对于日志的重要性以及日志框架的基本使用方法都了然于心。网络

在绝大多数时候，日志都是帮助咱们定位问题的利器，但全部事物都有两面性，有时它也会成为问题的导火索。app

接口莫名其妙变慢？

通常来讲，接口的响应时间基本都花在网络、DB层、IO层或者部分计算上，但我某一次排查B端线上问题时，居然发现是因为打印日志拖垮了整个接口。框架

因为老系统的某个业务异常处理不合理，致使有大量的错误日志输出，进而形成当前线程阻塞，机器负载升高，整个接口的吞吐量下降。异步

定义这种莫名其妙的问题倒也简单：ide

查看机器磁盘是否异常（磁盘占用、文件大小）
经过Jstack命令检查占用较高的线程
观察日志输出状况（异常状况下很是明显）

PS：当时的处理方案是优化了日志输出，同时将同步日志调整为异步日志工具

线上CPU飙赠

咱们在看日志时都但愿准确，干净，可复制至其余工具进行分析，因此日志通常都会这么写：

log.info("Method :: Kerwin.Demo, Params: {}, Result:{}", JSONUtil.toJsonStr(demo), JSONUtil.toJsonStr(demo));
复制代码

这就涉及到了序列化操做，当此类日志数量较多，接口调用次数较高时（每分钟几十万的C端调用），CPU占用就会很是明显的升高，即便整个程序没有任何问题。

因此咱们须要使用日志框架的动态化调整日志级别的能力，这样一来咱们在编码阶段所留下的日志也不须要在上线前删除了，同时能够更灵活的应对线上问题的排查和平常使用。

如何动态配置日志级别

以Log4j2为例，咱们可能会这样配置根节点（ROOT Logger）

<Loggers>
    <AsyncRoot level="ERROR" includeLocation="true">
        <AppenderRef ref="INFO_LOG"/>
        <AppenderRef ref="ERROR_LOG"/>
    </AsyncRoot>
</Loggers>
复制代码

使用如下代码，并查看日志文件

@Slf4j
public class LogTest {
    public static void main(String[] args) {
        log.info("This is a Demo...");
    }
}
复制代码

由于我调整ROOT的日志级别为ERROR，所以无任何日志输出

利用Log4j2提供的能力，修改日志级别，以下所示：

@Slf4j
public class LogTest {
    public static void main(String[] args) {
        log.info("This is a Demo... 111");
        Level level = Level.toLevel("info");
        LoggerContext context = (LoggerContext) LogManager.getContext(false);
        Configuration configuration = context.getConfiguration();
        configuration.getLoggerConfig("ROOT").setLevel(level);
        context.updateLoggers(configuration);
        log.info("This is a Demo... 222");
    }
}
复制代码

结果以下所示：

很是容易的实现了修改日志级别的能力，所以咱们在构建本身的应用或者系统时，可使用ZK进行动态化配置，也可使用HTTP或RPC接口留一个后门，以此来实现动态调整的能力。

如何配置指定类的日志级别

上面的代码演示了如何动态配置ROOT Logger节点，若是您在阅读本文时能使用IDE，天然能看到

org.apache.logging.log4j.core.config.Configuration#getLoggers，该方法包括了每个自定义logger的配置参数，一样可使用上述方式进行配置和修改。

代码范例：

String packetLoggerName = "log.demo";
Level level = Level.toLevel("DEBUG");
LoggerContext context = (LoggerContext) LogManager.getContext(false);
Configuration configuration = context.getConfiguration();
for (Map.Entry<String, LoggerConfig> entry : configuration.getLoggers().entrySet()) {
    if (packetLoggerName.equals(entry.getKey())) {
        entry.getValue().setLevel(level);
    }
}

context.updateLoggers(configuration);
复制代码

下图则是咱们的日志级别配置：

疑问：框架如何处理没有Logger的类

先说结论：

每个Logger不必定都有其对应的配置
实际工做的Logger并不必定是其自己，如上文中的：log.demo.test.LogTestApp
Logger之间具备继承性，即log.demo.test.LogTestApp在不做其余额外配置的状况下，会使用父级配置：log.demo，以此类推直到ROOT

使用如下配置及代码，便可进行验证：

<Loggers>
     <AsyncRoot level="INFO" includeLocation="true">
         <AppenderRef ref="Console"/>
     </AsyncRoot>

     <logger name="log.demo" level="ERROR">
         <AppenderRef ref="ERROR_LOG"/>
     </logger>
</Loggers>
复制代码

@Slf4j
public class LogTestApp {
    public static void main(String[] args) {
        System.out.println(log.getName());
    }
}

// 输出结果
// log.demo.test.LogTestApp
复制代码

经过观察配置文件，咱们能够很明显的发现，整个日志框架其实是不存在：log.demo.test.LogTestApp 这个Logger的，那它究竟是如何工做的呢？

核心代码分析以下：

private static final Logger log = LoggerFactory.getLogger(LogTestApp.class);
复制代码

经过工厂的方式建立一路跟源码，能够发现类：AbstractConfiguration

@Override
public LoggerConfig getLoggerConfig(final String loggerName) {
    LoggerConfig loggerConfig = loggerConfigs.get(loggerName);
    if (loggerConfig != null) {
        return loggerConfig;
    }
    String substr = loggerName;
    while ((substr = NameUtil.getSubName(substr)) != null) {
        loggerConfig = loggerConfigs.get(substr);
        if (loggerConfig != null) {
            return loggerConfig;
        }
    }
    return root;
}
复制代码

该方法的做用就是给每个类的Logger绑定实际的执行者，其中NameUtil.getSubName()方法即获取当前类的全路径的上一层，经过循环遍历找到最近（所谓最近即以包名为界限，由子向父级递推）的Logger。

了解完以上的特性，咱们也就有了问题的答案。

按需配置父级Logger

随着工程化的推动，系统代码的层次性很是明显，以我司为例，主要分为：Dao、Service、Business、Api这四层，其中核心业务通常都放在Business层，因此在通常状况下出问题也都发生Business层，咱们能够配置如下Logger，动态调整全部的Business的日志级别，以达到更加精准的控制：

<Loggers>
    <logger name="com.jd.o2o.business" level="INFO">
        <!-- INFO_LOG -->
    </logger>
</Loggers>
复制代码

同理，若是须要关注DB层的话，也能够配置父级Logger来监控DB层的日志。

动态生成Logger

其实从上文中动态调整日志级别就能够发现一些端倪，既然日志框架支持动态刷新配置，那么它必定支持动态新增配置（即便当前版本不支持，也只是还没有开发）。

经过阅读源码，能够看出如下方法能够知足咱们的要求：

org.apache.logging.log4j.core.config.Configuration#addLogger

PS：我的不建议使用该种方式，由于编码相对繁琐，且过于灵活反而致使问题很差排查

疑问：莫名其妙的输出

有时候咱们也会遇到这种问题：某一个Logger我想让它打ERROR日志，只输出到ERROR文件，结果它输出到了INFO、ERROR，这是为何？

这实际上是日志框架的设计问题，核心代码以下所示：

private void processLogEvent(final LogEvent event, final LoggerConfigPredicate predicate) {
    event.setIncludeLocation(isIncludeLocation());
    if (predicate.allow(this)) {
    	callAppenders(event);
    }
    logParent(event, predicate);
}
复制代码

日志事件在打印时，会传递给全部的Appenders，最后它还会向父级Logger传递日志事件，这也就致使咱们明明只配置了ERROR，结果却输出到了INFO和ERROR。

观察以下代码便可找到解决办法：

// 核心代码
private void logParent(final LogEvent event, final LoggerConfigPredicate predicate) {
    if (additive && parent != null) {
        parent.log(event, predicate);
    }
}

// 解决办法 additivity置为false
<logger name="log.demo" level="INFO" additivity="false"></logger>
复制代码

打印日志的小技巧

在日志使用中除了正确的打印以外也存在一些小Tips，好比：

方案一：

log.info("This is a Demo, Request:{}", JSONUtil.toJsonStr(new LogTest()));
复制代码

方案二：

if (log.isInfoEnabled()) {
    log.info("This is a Demo, Request:{}", JSONUtil.toJsonStr(new LogTest()));
}
复制代码

以上两种方式你会选择哪种呢？其实对比就能看出来，必定会选择方案二，由于它能够避免没必要要的序列化。

总结

大部分时间日志都是程序员的好朋友，但一些微妙的状况它反而会成为致命的风险，因此咱们须要熟悉它的配置，了解它的原理。

那么如何用好日志框架呢，下面是几点建议：

使用Slf4j的进行桥接，避免直接使用某一个特定日志框架
合理设置RootLogger及其子Logger，能够将系统依赖的框架级日志分别输出至指定的文件中，便于问题的排查
合理利用动态日志级别的能力，随时调整线上日志级别
减小日志中的序列化行为，在使用低级别日志时须要判断当前日志级别是否开启，避免没必要要的序列化
如无特殊场景要求，尽可能使用高吞吐的异步日志

若是以为这篇内容对你有帮助的话：

固然要点赞支持一下啦~
另外，能够搜索并关注公众号「是Kerwin啊」，一块儿在技术的路上走下去吧~ 😋