减少条件跟踪/记录调用的开销答案

【问题标题】：Overhead reduction of conditional trace/logging calls减少条件跟踪/记录调用的开销
【发布时间】：2015-05-01 20:19:00
【问题描述】：

为了跟踪和调试我的Java 代码，我使用的是简单的Util 类而不是成熟的日志框架：

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) {...} 括号保存在我的跟踪调用周围。但是，无论调试级别如何，都必须在运行时准备和传递调用的参数。

我的问题：

我如何推动编译时优化器或 JVM 删除多余的跟踪调用？我正在考虑C/C++函数内联的行。

关于C# 的相关问题已在here 进行了讨论。但我不确定如何将建议的答案移植到Java。另一个来自 2010 年的 related post 讨论了与我类似的方法。我想知道是否真的需要像ProGuard 这样的第三方工具来解决这样一个常见的任务。

【问题讨论】：

为什么不使用现有的日志记录 API，例如 SLF4J？
如果您使用 java 8，您可以将 lambda 表达式传递给您的 info 方法，而不是 String。然后你可以在执行代码之前检查调试级别。
不确定是否可以告诉 Hotspot 重新评估代码，问题是它是否真的很重要。在 99% 的情况下，您的时间关键型应用无论如何都不会被中间跟踪。
@isnot2bad：如果现有的日志框架解决了这个问题，我很想知道他们是如何做到的。到目前为止，日志框架的复杂性让我有点不知所措。
不，我不认为任何记录器可以操纵 JIT 统计信息，但是它们中的大多数都使用 Object 参数推广内置格式化程序，这在大多数微不足道的情况下都有帮助。

标签： java performance debugging trace

【解决方案1】：

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

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

像SLF4J 这样的一些日志API 还提供了更复杂的日志方法，可以接受格式字符串和多个参数，因此只有在启用日志级别的情况下才会生成日志消息：

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

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

从 Java 8 开始，您还可以利用 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 的“板载”解决方案轻松交换您的日志记录实现。

【讨论】：

“我不知道已经支持的日志 API。” 实际上，Java 的 java.util.logging.Logger（在引入 lambdas 时）支持开箱即用.例如，有一个Logger#info(Supplier<String> msgSupplier) 方法。
@JoshuaTaylor 谢谢 - 你是对的。不知道为什么我没有看到这些额外的 1.8 方法。我已经更新了我的答案以解决您的言论。

【解决方案2】：

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

您可以使用 Java 8 java.util.functions.Supplier<String> 进行花边评估，但我认为可能没有性能可以超越显式级别的测试用例。

记录器看起来像：

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

你可以像这样使用它：

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

【讨论】：

【解决方案3】：

由于其复杂性，不使用已建立的日志框架似乎很奇怪，但担心诸如方法内联之类的小优化，同时忽略了格式化日志字符串而不考虑日志级别的更大问题。但如果你坚持重新发明轮子：

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

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

以下两行将产生完全相同的输出。但是，在禁用日志记录语句的情况下，第二种形式的性能至少比第一种形式高 30 倍。
logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

值得注意的是，参数（此处为：entry）的类型为 Object，因此只有在确实需要记录消息时才会将它们转换为 String。

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

【讨论】：