logback isDebugEnabled() 在多核 CPU 上是否慢？答案

【问题标题】：Is logback isDebugEnabled() slow on a multi core CPU?logback isDebugEnabled() 在多核 CPU 上是否慢？
【发布时间】：2014-07-11 08:51:44
【问题描述】：

我们目前正在为医疗档案开发基于 Scala 和 Akka Cluster 的产品。代码中有很多

if(logger.isDebugEnabled()) {
    logger.debug(expensiveFunction())
}

在我们之前使用标准 SQL/JPA、阻塞 I/O 和大量线程的代码中，这种构造或多或少是免费的。然而，在反应式编程时代的今天，CPU 缓存同步以及内存屏障和锁被认为是昂贵的，应该避免使用。 Logback isDebugEnabled() 是否会导致易失性访问，从而导致内存屏障。如果是这样，大量的 logger.isDebugEnabled() 是否会成为潜在的性能杀手？

有一篇关于 CPU 缓存同步和内存屏障主题的优秀博文： http://mechanical-sympathy.blogspot.se/2013/02/cpu-cache-flushing-fallacy.html

【问题讨论】：

它比不做检查的替代方法要快得多。作为替代方案，您有什么建议？
BTW 它仍然比使用 Scala 或在线程之间传递消息便宜得多。
它比使用 scala 的 Int 而不是 int 便宜。
感谢 cmets。我同意不稳定的访问仍然比例如便宜得多。在线程之间发布，但如果 isDebugEnabled() 施加了内存屏障，则应该在内部循环中避免它。另一种方法是了解影响并尝试将日志记录更稀疏地放置在循环之外。
或者只是缓存循环前的值。我不知道 Scala，但在 Java 中：boolean isDebugEnabled = logger.isDebugEnabled(); ...稍后... if(isDebugEnabled) logger.debug(expensiveFunction());

标签： java performance logback volatile memory-barriers

【解决方案1】：

编辑：正如 OP 所指出的，此代码来自 Log4J，而不是 Logback。可以检查 Logback 代码 here，这似乎很复杂（这只是我的观点，但我不喜欢方法名称像 filterAndLog_0_Or3Plus 这样的代码）

如果你查看source code:

 public boolean isDebugEnabled() {
    if(repository.isDisabled( Level.DEBUG_INT))
      return false;
    return Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel());
  }



 public void debug(Object message) {
    if(repository.isDisabled(Level.DEBUG_INT))
      return;
    if(Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel())) {
      forcedLog(FQCN, Level.DEBUG, message, null);
    }
  }

所以不，你不应该担心性能，因为它无论如何都会被调用，所以在将字符串创建为 log.debug(str1 + obj.toString()) 之前使用它仍然是一个好主意。

【讨论】：

我认为来源来自 Log4j。 getEffectiveLevel() 确实访问了一个 volatile 变量。从 Logback 源中，我无法得出是否强制执行内存屏障的结论。当然，isDebugEnabled() 比不检查要好得多，但问题是是否应该完全避免它，因为 volatile 变量访问的成本。

【解决方案2】：

查看 logback 代码，isDebugEnabled() 内部没有访问任何锁或 volatile。

但是，对于非常紧凑的循环，我建议这样做：

boolean isDebugEnabled = log.isDebugEnabled();

while(cond) {
    if (isDebugEnabled) {
        log.debug(...);
    }
    doStuff();
}

如果您的逻辑在紧密循环中被调用，但循环在另一个类中，则将 isDebugEnabled 设为最终成员变量并在构造函数中对其进行初始化。这可以带来出色的性能，因为热点会看到“if (false)”并删除代码。唯一的缺点是您不能即时更改日志级别，但这在大多数系统中并不是什么大问题。

【讨论】：

【解决方案3】：

回答这个问题的最佳方法是在目标硬件和负载上对您的程序进行基准测试，通过配置禁用日志记录，一次将字段标记为 volatile，一次则不是。

也就是说，如果这对性能产生可衡量的影响，我会感到非常惊讶，原因如下：

您的程序可能只在 isDebugEnabled() 中花费总执行时间的一小部分。
据Is volatile expensive?：

一般而言，在大多数现代处理器上，易失性负载与正常负载相当。 volatile 存储大约是 montior-enter/monitor-exit 时间的 1/3。这在缓存一致的系统上可以看到。

【讨论】：