减少条件 trace/logging 调用的开销

Overhead reduction of conditional trace/logging calls

为了跟踪和调试我的 Java 代码,我使用了一个简单的 Util class 而不是成熟的日志记录框架:

public class Util {
    public static int debugLevel;

    public static void info(String msg) {
      //  code for logfile output
      //  handling of unprintable characters
      //  etc. omitted 
      System.out.println(msg);
    }

    public static void info4(String msg) {
        if (debugLevel >= 4) {
           info(msg);
        }
    }
}

这允许紧凑的单行语句,如下所示:

info4(String.format("%16s: ", host) + Util.toHex(sidNetto));

使用 debugLevel 变量,我可以控制程序的冗长程度。通常,调试级别在执行开始时全局设置。但它也可以在常规水平上进行局部调整。

基本上,我在跟踪调用周围保存了重复的 if (debugLevel >= DEBUG_ALL) {...} 括号。但是,无论调试级别如何,都必须在运行时准备和传递调用的参数。

我的问题:

How could I nudge the compile-time optimizer or the JVM to remove superfluous trace calls? I am thinking on the lines of C/C++ function inlining.

讨论了一个关于 C# 的相关问题 here。但我不确定如何将建议的答案移植到 Java。 实际上还需要 related post back from 2010 discussed similar approaches to mine. Im wondering if third-party tools like ProGuard 来解决这样一个常见的任务。

大多数日志框架都是这样做的。对于轻量级参数(这包括内置格式化程序,这是一个很好的最佳实践)不要检查级别,否则在序列化复杂的字符串参数之前检查级别。

您可以使用 Java 8 java.util.functions.Supplier<String> 进行花边评估,但我认为可能无法获得超过显式级别测试用例的性能。

记录器看起来像:

void debug(String ptrn, Supplier<String> args...)

您可以像这样使用它:

debug("Hello {0}", this::getName());

我知道的大多数日志记录 API 建议在实际调用日志方法之前检查日志级别是否启用,以防必须先准备消息,例如:

if (logger.isTraceEnabled()) {
    String msg = String.format("Name changed from %s to %s", oldName, newName);
    logger.trace(msg);
}

一些日志记录 API 像 SLF4J 也提供了更复杂的日志方法,它们接受格式字符串和多个参数,因此只有在启用日志级别的情况下才会生成日志消息:

logger.trace("Name changed from {} to {}", oldName, newName);

这在大多数情况下就足够了,但有时您的消息构建起来更复杂,或者必须先将参数转换为字符串。在这种情况下,检查日志级别仍然是一个很好的方法。

从 Java8 开始,您还可以利用 lambda 表达式来解决这个问题。您的日志方法可以这样实现:

public void log(Supplier<String> messageSupplier) {
    if (isLogEnabled()) {
        String msg = messageSupplier.get();
        // TODO: log msg
    }
}

如您所见,只有在启用日志记录的情况下才会从 messageSupplier 检索消息。感谢 lambda 表达式,实现 Supplier<String> 非常容易:

logger.log(() -> String.format("Name changed from %s to %s", oldName, newName));

更新(感谢 Joshua Taylor)

从 Java 8 开始,java.util.logging API 已经支持消息供应商,例如请参阅 Logger#info,因此您可以通过 JRE 的 'on-board' 解决方案轻松交换您的日志记录实现。

不使用已建立的日志记录框架似乎很奇怪,因为它们很复杂,而是担心像方法内联这样的小优化,同时忽略格式化日志字符串的更大问题,无论日志级别如何。但如果你非要重新发明轮子:

JVM(至少是Oracle热点JVM)自动内联短方法,并对不可达分支进行死码剔除。要被检测为无法访问,消息的日志级别和级别阈值必须是常量(编译时常量或静态最终)。否则,JVM 将比较每次调用的日志记录级别,尽管它仍然可能执行推测内联(内联通常采用的分支,由条件分支指令保护)以确保仅在异常情况下执行分支指令。

然而,更值得关注的是构建日志消息的成本,只有在必须实际记录消息时才会产生这种成本。要求调用代码在准备消息之前检查是否启用日志记录的旧 log4j 方法相当冗长且容易被遗忘。相反,SLF4J 通过让日志方法采用格式字符串和可变数量的对象插入到占位符中,将字符串连接推迟到日志系统。 SLF4J 常见问题 writes:

The following two lines will yield the exact same output. However, the second form will outperform the first form by a factor of at least 30, in case of a disabled logging statement.

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

值得注意的是,参数(此处:entry)的类型为 Object,因此它们转换为 String 只有在实际必须记录消息时才会发生。

要明确的是,没有可靠的方法可以通过重新定义方法来跳过方法参数的评估,因为这种消除只有在即时编译器可以证明评估没有副作用的情况下才会发生,这是热点jvm 只检测它是否内联了整个评估,它只会对非常简单的评估进行内联。因此,API 将格式化移动到日志系统中的解决方案可能是您所希望的最好的解决方案。