java 如果isDebugEnabled(),则将对debug()的调用括在中:一个好政策?

2jcobegt  于 2023-01-24  发布在  Java
关注(0)|答案(7)|浏览(130)

我们的团队有这样的策略

if (LOGGER.isDebugEnabled()) {  
  LOGGER.debug("model[" + model + "]");
}

而不是像这样简单地调用logging方法:

LOGGER.debug("model[" + model + "]");

这种做法能够带来一些性能改进,但另一方面,它使代码库更加复杂。我们的应用程序没有性能问题,可能永远不会,引入该策略的理由很简单,这是一个很好的做法,所以它应该在我们每次做日志记录时使用。
你觉得这是个好政策吗?

insrf1ej

insrf1ej1#

您应该使用 SLF4J 并使 log4j 成为您的实现。使用 SLF4J,您可以通过使用参数化消息来完全消除isDebugEnabled()
请参见slf4j FAQ中有关日志性能的部分
下面两行将产生完全相同的输出。但是,如果日志记录语句被禁用,第二种形式的性能将超过第一种形式至少30倍。
logger.debug("The new entry is " + entry + ".");
logger.debug("The new entry is {}.", entry);

holgip5t

holgip5t2#

当您构建的日志字符串实际上会显著影响性能时,这是一个很好的策略。这可能有两个原因:

  • 构建字符串需要做大量的工作(例如,它必须进行查找,或者从许多非常小的片段构建一个非常大的字符串)
  • 它在一个循环中,不做其他工作(但被调用得非常频繁),因此构建一个简单的日志字符串所花费的时间比例也更高

这不应该是一个笼统的规则,我希望这两种情况都是相对罕见的。
当然,我们真正想要的是能够说,“调用debug方法,传入一个参数,该参数不是调试字符串本身,而是知道如何 * 构建 * 调试字符串的东西,当且仅当它是必要的时候。”如果没有简洁的闭包,这在Java中会很难看。(即使在一种以lambda表达式的形式使用闭包的语言中,捕获相关变量在某些情况下也是非常重要的,这取决于语言如何处理捕获。)

ne5o7dgx

ne5o7dgx3#

我同意Michael A. Jackson的名言:
程序优化的第一条规则:不要这样做。
程序优化的第二条规则-仅限Maven:先别这么做。
我认为,在大多数情况下,如果不确定性能增益是否显著,就不值得将代码库变得更加复杂。
我知道性能的提高,但是我认为在特定的情况下,决定是否值得添加这些额外的代码行应该是每个程序员的责任。在大多数情况下,额外的代码行只是增加了复杂性,而在性能方面没有任何显著的好处。

yx2lnoni

yx2lnoni4#

我在网上找不到参考资料(也许我是在书中读到的),但是有一个例子是一些BIOS调用将字符串写入屏幕。
将字符串写入屏幕的代码会进行检查,以确保字符串不会离开屏幕,然后调用一个函数将一个字符写入屏幕。
将字符写入屏幕的函数会进行检查,以确保字符不会从屏幕中删除。
从将字符写入屏幕的函数中删除检查代码可以大大提高速度,因为打印每个字符的情况非常频繁,他们还提供了一个方法,可以检查调用前没有检查屏幕位置的情况。
因此,如果您可以在高级别进行检查,而避免在低级别进行检查,则可以显著加快速度。
在您提供的情况下,如果代码在循环中,或者如果有很多日志记录语句,那么将有明显的好处,因为您可以:

  • 删除字符串创建(以及关联的GC)
  • 减少if语句的数量(尽管hotspote很可能会优化它们)。

我想说的是,一般来说,如果有简单的解决方法,就不应该添加任何已知的代价高昂的语句,这显然福尔斯那种情况--添加if语句并不难,但以后添加会很麻烦,而且它提供了明确的速度/内存改进。
我认为这和过早优化的区别在于,这是众所周知的代价很高的,所以问题归结为,你是否想把累积的代价加到程序中,这个代价几乎是恒定的,在编写代码时就知道了。

tzcvj98z

tzcvj98z5#

我认为在你写日志消息之前调用isDebugEnabled()是有意义的。这样你就可以很容易地在以后更新你的日志消息。我们使用下面的代码来使日志消息更灵活。

if (LOGGER.isDebugEnabled()) {  
  String msg = "A Message {0} you can put {1} differet Objects in {2}"; //$NON-NLS-1$
  Object[] args = new Object[] {file1.toString(),new Integer(23),anObject};
  LOGGER.debug(MessageFormat.format(msg,args));
}

当你没有if语句时,你会浪费时间。记住...你的项目会变大,你的日志消息也会变大。
日志消息不应该减慢您的代码!

dtcbnfnu

dtcbnfnu6#

如果“model”是已知的,那么仅仅记录它并不那么昂贵,但是,如果“model”应该被提取来仅仅用于记录,那么简单性就会大打折扣。

LOGGER.debug("model[" + proxy.getModel() + "]");
b1payxdu

b1payxdu7#

我将记录器设置为INFO级别,并运行了以下测试:

@Test
void loggerTest() {
    System.out.println("START " + LocalDateTime.now());

    System.out.println("TRACE: " + LocalDateTime.now());
    log.trace("{}", sleepAndReturnString(5000L, "TRACE PRINT"));
    System.out.println("DEBUG: " + LocalDateTime.now());
    log.debug("{}", sleepAndReturnString(5000L, "DEBUG PRINT"));
    System.out.println("INFO: " + LocalDateTime.now());
    log.info("{}", sleepAndReturnString(5000L, "INFO PRINT"));
    System.out.println("WARN: " + LocalDateTime.now());
    log.warn("{}", sleepAndReturnString(5000L, "WARN PRINT"));
    System.out.println("ERROR: " + LocalDateTime.now());
    log.error("{}", sleepAndReturnString(5000L, "ERROR PRINT"));

    System.out.println("END " + LocalDateTime.now());
}

public static String sleepAndReturnString(long millis, String message) {
    try {
        Thread.sleep(millis);
    } catch (InterruptedException e) {
        log.error("", e);
    }
    return message;
}

logback.xml文件:

<configuration>

<property name="MY__PATTERN"
          value="%d{yyyy-MM-dd HH:mm:ss.SSS} | %highlight(%-5level) | %message%n%rEx"/>

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
        <outputPatternAsHeader>true</outputPatternAsHeader>
        <pattern>${MY__PATTERN}</pattern>
    </encoder>
</appender>

<root level="info">
    <appender-ref ref="CONSOLE"/>
</root>

以下是控制台中打印的内容:

START 2023-01-20T11:17:57.255
TRACE: 2023-01-20T11:17:57.255
DEBUG: 2023-01-20T11:18:02.256
INFO: 2023-01-20T11:18:07.262
2023-01-20 11:18:12.267 | INFO  | INFO PRINT
WARN: 2023-01-20T11:18:12.283
2023-01-20 11:18:17.285 | WARN  | WARN PRINT
ERROR: 2023-01-20T11:18:17.285
2023-01-20 11:18:22.287 | ERROR | ERROR PRINT
END 2023-01-20T11:18:22.287

正如我们所看到的,线程每次休眠5秒,尽管TRACE和DEBUG消息没有打印到控制台,这表明使用isLevelEnabled是合理的,并且提高了性能。

相关问题