本文正在参与「金石方案 . 分割6万现金大奖」

今天又是还愿的一天,今天的方案 提前完成,想起之前谈论区的一句话

/post/716304…

到底该不该写isDebugEnabled

这儿解答下

条件简介

到底该不该写isDebugEnabled

彩蛋在后边

目录

到底该不该写isDebugEnabled

链接

logback jira地址

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

logback filter 文章

logback.qos.ch/manual/filt…

is判别的必要性

即便不写is判别,debug也会对是否能够输出日志 进行判别

是的

源码解析

public boolean isDebugEnabled(Marker marker) {
    FilterReply decision = this.callTurboFilters(marker, Level.DEBUG);
    if (decision == FilterReply.NEUTRAL) {
        return this.effectiveLevelInt <= 10000;
    } else if (decision == FilterReply.DENY) {
        return false;
    } else if (decision == FilterReply.ACCEPT) {
        return true;
    } else {
        throw new IllegalStateException("Unknown FilterReply value: " + decision);
    }
}
//假如体系能够打印 debug,输出 FilterReply.NEUTRAL,假如不能,输出FilterReply.DENY
private FilterReply callTurboFilters(Marker marker, Level level) {
    return this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, (String)null, (Object[])null, (Throwable)null);
}

能够看到,经过一些判别,终究调用到了getTurboFilterChainDecision_0_3OrMore办法,再看debug代码

public void debug(String msg) {
    this.filterAndLog_0_Or3Plus(FQCN, (Marker)null, Level.DEBUG, msg, (Object[])null, (Throwable)null);
}
private void filterAndLog_0_Or3Plus(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
    FilterReply decision = this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
    if (decision == FilterReply.NEUTRAL) {
        if (this.effectiveLevelInt > level.levelInt) {
            return;
        }
    } else if (decision == FilterReply.DENY) {
        return;
    }
    //假如是 占位符 只有通过前面的判别才会履行到这,所以不会有拼接的功用问题
    this.buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
public void debug(String format, Object arg) {
    this.filterAndLog_1(FQCN, (Marker)null, Level.DEBUG, format, arg, (Throwable)null);
}

debug 也是履行了 getTurboFilterChainDecision_0_3OrMore

假如是 占位符 只有通过前面的判别才会履行到这,所以不会有拼接的功用问题,可是假如这个属性创立的内存耗费

小总结

不写is判别,输出日志的时分 也会判别

从这个角度 isDebugEnabled是能够不写的

即便体系不打印debug,新创立的目标也占用内存

预备东西

先要能验证 内存是否占用了,运用哪个东西呢?

也不用看到字节程度,直接多履行一些次数,然后看内存的差距就能够 用 java VisualVM

测验场景

看黄色的线

代码

private static final Integer count = 100;
@GetMapping("/testDebug")
public String testDebug() {
    for (int i = 0; i < count; i++) {
        log.debug(new B() + "3" + "4");//就算设置了不打印debug,也会履行内容的拼接,会影响功用
    }
    return "success";
}
@GetMapping("/testDebugForEnabled")
public String testDebugForEnabled() {
    for (int i = 0; i < count; i++) {
        if(log.isDebugEnabled()){
            log.debug(new byte[1024 * 1024] + "3" + "4");//就算设置了不打印debug,也会履行内容的拼接,会影响功用
        }
    }
    return "success";
}
public class B {
    private byte[] b = new byte[1024 * 1024];
    public B() {
        System.out.println("B的初始化");
    }
}

体系打印debug, 无 isDebugEnabled

到底该不该写isDebugEnabled

体系打印debug,有 isDebugEnabled

到底该不该写isDebugEnabled

体系不打印debug, 无 isDebugEnabled

到底该不该写isDebugEnabled

不管体系打不打印debug,假如没有isDebugEnabled 都会创立目标,占用内存

体系不打印debug,有 isDebugEnabled

到底该不该写isDebugEnabled

小总结

从上面的简略测验,能够得出

不管体系打不打印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代码

public void debug(String msg) {
    this.filterAndLog_0_Or3Plus(FQCN, (Marker)null, Level.DEBUG, msg, (Object[])null, (Throwable)null);
}
private void filterAndLog_0_Or3Plus(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
    FilterReply decision = this.loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);
    if (decision == FilterReply.NEUTRAL) {
        if (this.effectiveLevelInt > level.levelInt) {
            return;
        }
    } else if (decision == FilterReply.DENY) {
        return;
    }
    //假如是 占位符 只有通过前面的判别才会履行到这,所以不会有拼接的功用问题
    this.buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
public void debug(String format, Object arg) {
    this.filterAndLog_1(FQCN, (Marker)null, Level.DEBUG, format, arg, (Throwable)null);
}

假如是 占位符 只有通过前面的判别才会履行到这,所以不会有拼接的功用问题,可是假如这个属性创立的内存耗费

彩蛋

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

到底该不该写isDebugEnabled

怎样判别 每个日志 是否应该输出

其实咱们很多的便是 装备 包括info 以及以上的 日志输出

这儿就有2个点

  1. 体系装备的info 以上才能打印,这个是哪个参数办理的
  2. 有的时分 咱们在 application.yml文件中会指定哪几个包下的日志打印,又是怎样回事?

体系装备的info 以上才能打印,这个是哪个参数办理的

首要 假如这个让咱们自己完成,咱们必定也是 int标识,把优先级排序

比如

public final class Level implements java.io.Serializable {
    private static final long serialVersionUID = -814092767334282137L;
    public static final int OFF_INT = Integer.MAX_VALUE;
    public static final int ERROR_INT = 40000;
    public static final int WARN_INT = 30000;
    public static final int INFO_INT = 20000;
    public static final int DEBUG_INT = 10000;
    public static final int TRACE_INT = 5000;
    public static final int ALL_INT = Integer.MIN_VALUE;
}

这个没缺点,举一反三,咱们还会在哪这么运用

想到Rocketmq 也有类似的

public class MQVersion {
    //这儿ordinal 也是把版本号 变为int 进行比较
    public static final int CURRENT_VERSION = Version.V4_9_3.ordinal();
}

好,咱们持续,提到这,日志打不打印又是哪里控制的?

咱们首要要看

public enum FilterReply {
    DENY, NEUTRAL, ACCEPT;
}

分别代表着

  1. DENY 回绝
  2. NEUTRAL 中性
  3. ACCEPT 赞同
public boolean isDebugEnabled(Marker marker) {
    final FilterReply decision = callTurboFilters(marker, Level.DEBUG);
    //假如是中性 就需求进行后续判别
    if (decision == FilterReply.NEUTRAL) {
        return effectiveLevelInt <= Level.DEBUG_INT;
    } else if (decision == FilterReply.DENY) {
       //假如是回绝 履行返回false,不用打印了
        return false;
    } else if (decision == FilterReply.ACCEPT) {
       //假如是统一 履行返回true,需求打印
        return true;
    } else {
        throw new IllegalStateException("Unknown FilterReply value: " + decision);
    }
}

分隔分析

中性

又说回到 getTurboFilterChainDecision_0_3OrMore 办法了

final FilterReply getTurboFilterChainDecision_0_3OrMore(final Marker marker, final Logger logger, final Level level,
        final String format, final Object[] params, final Throwable t) {
    if (turboFilterList.size() == 0) {
        return FilterReply.NEUTRAL;
    }
    return turboFilterList.getTurboFilterChainDecision(marker, logger, level, format, params, t);
}

第一步判别 turboFilterList 是否为空

turboFilterList 是哪里初始化的呢?

到底该不该写isDebugEnabled

只找到了这个,debug一下

LoggingSystem的实例化

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

//源自package org.springframework.boot.logging;
public abstract class LoggingSystem {
	static {
		Map<String, String> systems = new LinkedHashMap<>();
		systems.put("ch.qos.logback.core.Appender",
				"org.springframework.boot.logging.logback.LogbackLoggingSystem");
		systems.put("org.apache.logging.log4j.core.impl.Log4jContextFactory",
				"org.springframework.boot.logging.log4j2.Log4J2LoggingSystem");
		systems.put("java.util.logging.LogManager",
				"org.springframework.boot.logging.java.JavaLoggingSystem");
		SYSTEMS = Collections.unmodifiableMap(systems);
	}
	public static LoggingSystem get(ClassLoader classLoader) {
		String loggingSystem = System.getProperty(SYSTEM_PROPERTY);
		if (StringUtils.hasLength(loggingSystem)) {//你也通过org.springframework.boot.logging.LoggingSystem来特殊指定
			if (NONE.equals(loggingSystem)) {
				return new NoOpLoggingSystem();
			}
			return get(classLoader, loggingSystem);
		}
		return SYSTEMS.entrySet().stream()
				.filter((entry) -> ClassUtils.isPresent(entry.getKey(), classLoader))
				.map((entry) -> get(classLoader, entry.getValue())).findFirst()
				.orElseThrow(() -> new IllegalStateException(
						"No suitable logging system located"));//取第一个
	}    
}    

这个其实便是 假如 有turboFilterList 数组,就开端 for循环处理,直到返回 FilterReply

for(int i = 0; i < len; ++i) {
    TurboFilter tf = (TurboFilter)tfa[i];
    FilterReply r = tf.decide(marker, logger, level, format, params, t);
    if (r == FilterReply.DENY || r == FilterReply.ACCEPT) {
        return r;
    }
}

说那么多没什么用,应该怎样用呢?

删除了剩余的东西(logback.xml)


<appender name="INFO-APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <!-- 过滤器,记载info等级以上的日志 -->
    <filter class="com.xxx.demo.springboot.test.C">
    </filter>
</appender>

发动之后给我报错

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

这就要提到 ClassLoader 的加载机制 这是由于

@Component
public class C extends TurboFilter {
    @Override
    public FilterReply decide(Marker marker, Logger logger, Level level, String s, Object[] objects, Throwable throwable) {
        return FilterReply.ACCEPT;
    }
}

后边换成

@Component
public class C   extends AbstractMatcherFilter<ILoggingEvent> {
    @Override
    public FilterReply decide(ILoggingEvent iLoggingEvent) {
        return FilterReply.ACCEPT;
    }
}

就好了,这个时分 你或许要问

不对啊,人家调用的时分 分明代码里是 转换成TurboFilter 履行的,我不是直接完成TurboFilter 就能够了么?

还真不是,这个里面还触及一个加载的事

到底该不该写isDebugEnabled

spi的加载 前面仍是native

这儿直接给结论,假如有兴趣能够后边写一篇

细节能够看 logback.qos.ch/manual/filt…

到底该不该写isDebugEnabled

这就需求提到 Filter和TurboFilter 差异

  1. TurboFilter目标绑定到日志上下文。因而,它们不仅在运用给定的追加器时被调用,而且在每次宣布日志记载恳求时都被调用。它们的范围比附加过滤器更广。
  2. 它们在LoggingEvent目标创立之前被调用。TurboFilter目标不需求实例化日志事情来过滤日志恳求。因而,turbo 过滤器用于高功用地过滤日志事情,甚至在事情创立之前。

其实就一句话 turbo在事情创立之前,不是一个功用

其实还没写完,可是真的累了。。。

到底该不该写isDebugEnabled

有机会持续补全。。。。

总结

一句话 我以为 isDebugEnabled 仍是要写的

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

到底该不该写isDebugEnabled