到底该不该写isDebugEnabled

╰半夏微凉° 2023-10-03 23:12 82阅读 0赞

序

今天又是还愿的一天，今天的计划 提前完成，想起之前评论区的一句话

juejin.cn/post/716304…

format_png

这里解答下

前提简介

format_png 1

彩蛋在后面

目录

format_png 2

链接

logback jira地址

[LOGBACK-1711] Deadlock when using Virtual Threads - QOS.ch JIRA

logback filter 文章

logback.qos.ch/manual/filt…

is判断的必要性

即使不写is判断，debug也会对是否可以输出日志 进行判断

是的

源码解析

  1. public boolean isDebugEnabled(Marker marker) {
  2.     FilterReply decision = this.callTurboFilters(marker, Level.DEBUG);
  3.     if (decision == FilterReply.NEUTRAL) {
  4.         return this.effectiveLevelInt <= 10000;
  5.     } else if (decision == FilterReply.DENY) {
  6.         return false;
  7.     } else if (decision == FilterReply.ACCEPT) {
  8.         return true;
  9.     } else {
  10.         throw new IllegalStateException("Unknown FilterReply value: " + decision);
  11.     }
  12. }
  13. //如果系统可以打印 debug，输出 FilterReply.NEUTRAL，如果不能，输出FilterReply.DENY
  14. private FilterReply callTurboFilters(Marker marker, Level level) {
  15.     return this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, (String)null, (Object[])null, (Throwable)null);
  16. }
  17. 复制代码

可以看到，经过一些判断，最终调用到了getTurboFilterChainDecision_0_3OrMore方法，再看debug代码

  1. public void debug(String msg) {
  2.     this.filterAndLog_0_Or3Plus(FQCN, (Marker)null, Level.DEBUG, msg, (Object[])null, (Throwable)null);
  3. }
  5. private void filterAndLog_0_Or3Plus(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
  6.     FilterReply decision = this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
  7.     if (decision == FilterReply.NEUTRAL) {
  8.         if (this.effectiveLevelInt > level.levelInt) {
  9.             return;
  10.         }
  11.     } else if (decision == FilterReply.DENY) {
  12.         return;
  13.     }
  14.     //如果是 占位符 只有通过前面的判断才会执行到这,所以不会有拼接的性能问题
  15.     this.buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
  16. }
  19. public void debug(String format, Object arg) {
  20.     this.filterAndLog_1(FQCN, (Marker)null, Level.DEBUG, format, arg, (Throwable)null);
  21. }
  22. 复制代码

debug 也是执行了 getTurboFilterChainDecision_0_3OrMore

如果是 占位符 只有通过前面的判断才会执行到这,所以不会有拼接的性能问题，但是如果这个属性创建的内存消耗

小总结

不写is判断，输出日志的时候 也会判断

从这个角度 isDebugEnabled是可以不写的

即便系统不打印debug，新创建的对象也占用内存

准备工具

先要能验证 内存是否占用了，使用哪个工具呢？

也不用看到字节程度，直接多执行一些次数，然后看内存的差距就可以 用 java VisualVM

测试场景

看黄色的线

代码

  1. private static final Integer count = 100;
  2. @GetMapping("/testDebug")
  3. public String testDebug() {
  4.     for (int i = 0; i < count; i++) {
  5.         log.debug(new B() + "3" + "4");//就算设置了不打印debug，也会执行内容的拼接，会影响性能
  6.     }
  8.     return "success";
  9. }
  12. @GetMapping("/testDebugForEnabled")
  13. public String testDebugForEnabled() {
  15.     for (int i = 0; i < count; i++) {
  16.         if(log.isDebugEnabled()){
  18.             log.debug(new byte[1024 * 1024] + "3" + "4");//就算设置了不打印debug，也会执行内容的拼接，会影响性能
  19.         }
  20.     }
  21.     return "success";
  22. }
  24. public class B {
  26.     private byte[] b = new byte[1024 * 1024];
  27.     public B() {
  28.         System.out.println("B的初始化");
  29.     }
  30. }
  31. 复制代码

系统打印debug, 无 isDebugEnabled

format_png 3

系统打印debug，有 isDebugEnabled

format_png 4

系统不打印debug, 无 isDebugEnabled

format_png 5

无论系统打不打印debug，如果没有isDebugEnabled 都会创建对象，占用内存

系统不打印debug，有 isDebugEnabled

format_png 6

小总结

从上面的简单测试，可以得出

无论系统打不打印debug，如果没有isDebugEnabled 都会创建对象，占用内存

还是需要使用isDebugEnabled的，能节省内存的消耗

虽然我们平时工作中一般都是debug日志 上生产会关闭，而且 一般日志打印的也都是一些现成的对象，而不是新建的对象，但是 还是推荐添加 isDebugEnabled

额外问题

之前为什么会有需要写is 判断呢？

在N久以前，很多日志框架都不支持{}模板的写法(如Log4j1.X, Apache Commons Logging)，于是只能通过字符串拼接来输出日志内容：

log.debug(“hello, this is “ + name);

这样一来，每当JVM执行到此时，不管你当前的日志级别是多少，都会执行一次字符串拼接，然后将结果做为形参传递给debug()方法，这样就带来了无用的性能损耗。这时，提前判断isDebugEnabled()可以解决此问题

if (log.isDebugEnabled()) { log.debug(“hello, this is “ + name); }

这样写的好处有二：

当日志级别在DEBUG以下时，log.debug(“hello, this is “ + name)就不会执行，从而没有字符串拼接的开销。 JIT在运行时会优化if语句，如果isDebugEnabled()返回false, 则JIT会将整个if块全部去掉。

使用占位符 能解决String 拼接的消耗？

能

看debug代码

  1. public void debug(String msg) {
  2.     this.filterAndLog_0_Or3Plus(FQCN, (Marker)null, Level.DEBUG, msg, (Object[])null, (Throwable)null);
  3. }
  5. private void filterAndLog_0_Or3Plus(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
  6.     FilterReply decision = this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
  7.     if (decision == FilterReply.NEUTRAL) {
  8.         if (this.effectiveLevelInt > level.levelInt) {
  9.             return;
  10.         }
  11.     } else if (decision == FilterReply.DENY) {
  12.         return;
  13.     }
  14.     //如果是 占位符 只有通过前面的判断才会执行到这,所以不会有拼接的性能问题
  15.     this.buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
  16. }
  19. public void debug(String format, Object arg) {
  20.     this.filterAndLog_1(FQCN, (Marker)null, Level.DEBUG, format, arg, (Throwable)null);
  21. }
  22. 复制代码

如果是 占位符 只有通过前面的判断才会执行到这,所以不会有拼接的性能问题，但是如果这个属性创建的内存消耗

彩蛋

为了写这篇文章，把代码下载下来

format_png 7

怎么判断 每个日志 是否应该输出

其实我们很多的就是 配置 包括info 以及以上的 日志输出

这里就有2个点

  1. 系统配置的info 以上才能打印，这个是哪个参数管理的
  2. 有的时候 我们在 application.yml文件中会指定哪几个包下的日志打印，又是怎么回事？

系统配置的info 以上才能打印，这个是哪个参数管理的

首先 如果这个让我们自己实现，我们肯定也是 int标识，把优先级排序

比如

  1. public final class Level implements java.io.Serializable {
  3.     private static final long serialVersionUID = -814092767334282137L;
  5.     public static final int OFF_INT = Integer.MAX_VALUE;
  6.     public static final int ERROR_INT = 40000;
  7.     public static final int WARN_INT = 30000;
  8.     public static final int INFO_INT = 20000;
  9.     public static final int DEBUG_INT = 10000;
  10.     public static final int TRACE_INT = 5000;
  11.     public static final int ALL_INT = Integer.MIN_VALUE;
  13. }
  14. 复制代码

这个没毛病，举一反三，我们还会在哪这么使用

想到Rocketmq 也有类似的

  1. public class MQVersion {
  2.     //这里ordinal 也是把版本号 变为int 进行比较
  3.     public static final int CURRENT_VERSION = Version.V4_9_3.ordinal();
  5. }
  6. 复制代码

好，我们继续，说到这，日志打不打印又是哪里控制的？

我们首先要看

  1. public enum FilterReply {
  2.     DENY, NEUTRAL, ACCEPT;
  3. }
  4. 复制代码

分别代表着

  1. DENY 拒绝
  2. NEUTRAL 中性

  3. ACCEPT 同意

    public boolean isDebugEnabled(Marker marker) {

    1. final FilterReply decision = callTurboFilters(marker, Level.DEBUG);
    2. //如果是中性 就需要进行后续判断
    3. if (decision == FilterReply.NEUTRAL) {
    4.     return effectiveLevelInt <= Level.DEBUG_INT;
    5. } else if (decision == FilterReply.DENY) {
    6.    //如果是拒绝 执行返回false，不用打印了
    7.     return false;
    8. } else if (decision == FilterReply.ACCEPT) {
    9.    //如果是统一 执行返回true，需要打印
    10.     return true;
    11. } else {
    12.     throw new IllegalStateException("Unknown FilterReply value: " + decision);
    13. }

    }
    复制代码

分开分析

中性

又说回到 getTurboFilterChainDecision_0_3OrMore 方法了

  1. final FilterReply getTurboFilterChainDecision_0_3OrMore(final Marker marker, final Logger logger, final Level level,
  2.         final String format, final Object[] params, final Throwable t) {
  3.     if (turboFilterList.size() == 0) {
  4.         return FilterReply.NEUTRAL;
  5.     }
  6.     return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format, params, t);
  7. }
  8. 复制代码

第一步判断 turboFilterList 是否为空

turboFilterList 是哪里初始化的呢？

format_png 8

只找到了这个，debug一下

LoggingSystem的实例化

LoggingSystem被实例化那个，默认它取得顺序是LogbackLoggingSystem>Log4J2LoggingSystem>JavaLoggingSystem，如果类存在就选择。

  1. //源自package org.springframework.boot.logging;
  2. public abstract class LoggingSystem {
  3.     static {
  4.         Map<String, String> systems = new LinkedHashMap<>();
  5.         systems.put("ch.qos.logback.core.Appender",
  6.                 "org.springframework.boot.logging.logback.LogbackLoggingSystem");
  7.         systems.put("org.apache.logging.log4j.core.impl.Log4jContextFactory",
  8.                 "org.springframework.boot.logging.log4j2.Log4J2LoggingSystem");
  9.         systems.put("java.util.logging.LogManager",
  10.                 "org.springframework.boot.logging.java.JavaLoggingSystem");
  11.         SYSTEMS = Collections.unmodifiableMap(systems);
  12.     }
  13.     public static LoggingSystem get(ClassLoader classLoader) {
  14.         String loggingSystem = System.getProperty(SYSTEM_PROPERTY);
  15.         if (StringUtils.hasLength(loggingSystem)) {//你也通过org.springframework.boot.logging.LoggingSystem来特殊指定
  16.             if (NONE.equals(loggingSystem)) {
  17.                 return new NoOpLoggingSystem();
  18.             }
  19.             return get(classLoader, loggingSystem);
  20.         }
  21.         return SYSTEMS.entrySet().stream()
  22.                 .filter((entry) -> ClassUtils.isPresent(entry.getKey(), classLoader))
  23.                 .map((entry) -> get(classLoader, entry.getValue())).findFirst()
  24.                 .orElseThrow(() -> new IllegalStateException(
  25.                         "No suitable logging system located"));//取第一个
  26.     }    
  27. }    
  28. 复制代码

这个其实就是 如果 有turboFilterList 数组，就开始 for循环处理，直到返回 FilterReply

  1. for(int i = 0; i < len; ++i) {
  2.     TurboFilter tf = (TurboFilter)tfa[i];
  3.     FilterReply r = tf.decide(marker, logger, level, format, params, t);
  4.     if (r == FilterReply.DENY || r == FilterReply.ACCEPT) {
  5.         return r;
  6.     }
  7. }
  8. 复制代码

说那么多没什么用，应该怎么用呢？

删除了多余的东西（logback.xml）

  1. <appender name="INFO-APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
  2.     <!-- 过滤器，记录info级别以上的日志 -->
  3.     <filter class="com.xxx.demo.springboot.test.C">
  5.     </filter>
  7. </appender>
  8. 复制代码

启动之后给我报错

  1. ERROR in ch.qos.logback.core.joran.util.PropertySetter@f6efaab - "com.xxx.demo.springboot.test.C" was loaded by [sun.misc.Launcher$AppClassLoader@18b4aac2].
  2.     at org.springframework.boot.logging.logback.LogbackLoggingSystem.loadConfiguration(LogbackLoggingSystem.java:166)
  4. 复制代码

这就要说到 ClassLoader 的加载机制 这是因为

  1. @Component
  2. public class C extends TurboFilter {
  3.     @Override
  4.     public FilterReply decide(Marker marker, Logger logger, Level level, String s, Object[] objects, Throwable throwable) {
  5.         return FilterReply.ACCEPT;
  6.     }
  7. }
  8. 复制代码

后面换成

  1. @Component
  2. public class C   extends AbstractMatcherFilter<ILoggingEvent> {
  5.     @Override
  6.     public FilterReply decide(ILoggingEvent iLoggingEvent) {
  7.         return FilterReply.ACCEPT;
  8.     }
  9. }
  10. 复制代码

就好了，这个时候 你可能要问

不对啊，人家调用的时候 明明代码里是 转换成TurboFilter 执行的，我不是直接实现TurboFilter 就可以了么？

还真不是，这个里面还涉及一个加载的事

format_png 9

spi的加载 前面还是native

这里直接给结论，如果有兴趣可以后面写一篇

细节可以看 logback.qos.ch/manual/filt…

这就需要说到 Filter和TurboFilter 区别

  1. TurboFilter对象绑定到日志上下文。因此，它们不仅在使用给定的追加器时被调用，而且在每次发出日志记录请求时都被调用。它们的范围比附加过滤器更广。
  2. 它们在LoggingEvent对象创建之前被调用。TurboFilter对象不需要实例化日志事件来过滤日志请求。因此，turbo 过滤器用于高性能地过滤日志事件，甚至在事件创建之前。

其实就一句话 turbo在事件创建之前，不是一个功能

其实还没写完，但是真的累了。。。

format_png 10

有机会继续补全。。。。

总结

一句话 我认为 isDebugEnabled 还是要写的

java-tools Idea 插件 在完善，满足一些开发中使用的功能，写篇文章真的累 不行，我要去吃口饭了

format_png 11

作者：雨夜之寂
原文链接：https://juejin.cn/post/7176087632215015461

发表评论

表情：
评论列表 （有 0 条评论，82人围观）

还没有评论，来说两句吧...

相关阅读

    相关 到底该不该使用Python?

    最近，大家总在吐槽Python：“虽然它是一种不错的语言，但不适用于专业领域。” 前不久，我在LinkedIn上找到一篇帖子，主要建议初级开发人员应该学习哪种语言，以便获得更

    朱雀朱雀/ 0 赞/ 177 阅读

    相关 到底该不该办网呢？？？

    最近一直在考虑一个问题，该不该办宽带，我是个爱玩的人，要是再办了网我真怕自己整天上网玩了。。。![Image 1][] 但是又一想，办上网之后学习也能方便得多了呀。可以随时上

    忘是亡心i忘是亡心i/ 0 赞/ 578 阅读