Java日志框架中需要判断log.isDebugEnabled()吗？

背景

在日常开发中，项目会使用抽象日志接口slf4j来打印日志。如下是一段典型的打印日志代码：

logger.debug("hello, world");

但是在一些项目或第三方开源框架中，也会发现有些代码在输出日志时，在前面添加if判断，代码如下：

if(logger.isDebugEnabled()){
    logger.debug("hello, world");
}

简单来说，先使用isDebufEnabled来判断日志级别。这么写的目的是什么呢？而且网上有些文档指出这种判断其实是不需要的。那实际开发中，我们到底要不要判断isDebugEnabled呢？希望通过这篇文章来分享一些我对日志打印的思考。

简单的源码剖析

有些人不明白为什么要添加if判断，会认为这样是为了控制日志的输出。其实这是不对的。对于下面的两段代码：

logger.debug("hello, world")
if(logger.isDebugEnabled()){
    logger.debug("hello, world");
}

如果应用的日志级别大于debug，比如为info。那么这两段代码，最终都不会输出日志。在debug方法内部，会判断日志级别，如果应用级别大于日志级别，就不会输出日志。以下是isDebugEnabled和debug的核心代码（我删除了一些无关代码）：

isDebugEnabled方法：

public boolean isDebugEnabled(Marker marker) {
        final FilterReply decision = callTurboFilters(marker, Level.DEBUG);
        if (decision == FilterReply.NEUTRAL) {
            return effectiveLevelInt <= Level.DEBUG_INT;
        } else {
            throw new IllegalStateException("Unknown FilterReply value: " + decision);
        }
    }

debug方法：

private void filterAndLog_0_Or3Plus(final String localFQCN, final Marker marker, final Level level, final String msg, final Object[] params,
                    final Throwable t) {

        final FilterReply decision = loggerContext.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg, params, t);

        if (decision == FilterReply.NEUTRAL) {
            if (effectiveLevelInt > level.levelInt) {
                return;
            }
        } else if (decision == FilterReply.DENY) {
            return;
        }

        buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
    }

那么问题来了，既然isDebugEnabled不会影响日志是否输出，那为什么要添加这个判断呢？

为什么要添加if判断

我们考虑下面几段代码：

代码清单一：

logger.debug("hello, world")

代码清单二：

if(logger.isDebugEnabled()){
    logger.debug("hello, world")
}

代码清单三：

logger.debug("hello" + "world");

代码清单四：

logger.debug(String.format("hello, %s", "world"))

代码清单五：

logger.debug("hello {}", "world");

以上5段代码，如果应用日志级别为info，那么这5段代码都不会输出日志。它们的差异其实是性能不同。下面我们来逐个分析。

  • 代码清单一：执行debug方法。debug方法内部判断日志级别，然后退出。
  • 代码清单二：isDebugEnabled判断日志级别，然后退出。
  • 代码清单三：先拼接字符串“hello”和“world”。然后执行debug方法。
  • 代码清单四：先执行String.format方法，然后执行debug方法。
  • 代码清单五：执行debug方法。

大家发现了吗？虽然最终都不会输出日志，但这5段代码还是有差异的。代码清单三和代码清单四分别执行了"+"字符串拼接和String.format方法，但最终却没用到。也就是说，这两段代码执行了一些无用操作，造成了额外的性能损耗。

所以，代码清单二中添加isDebugEnabled可以避免无用的字符串操作，提高性能。

isDebugEnabled是必需的吗？

上一节中，我提到使用isDebugEnabled可以提升性能，那是不是在所有地方都需要添加isDebugEnabled判断呢？

先说结论，不是的。应该根据具体场景来判断是否添加isDebugEnabled。

比如下面的代码：

logger.debug("hello, world");

打印一条日志“hello，world”。那么这时候就不用添加isDebugEnabled判断了。关于isDebugEnabled的使用场景，总结了如下的最佳实践：

isDebugEnabled最佳实践

原则一：如果打印字符串常量，不需要isDebugEnabled

比较下面两段代码：

logger.debug("hello, world");
if(logger.isDebugEnabled()){
    logger.debug("hello, world");
}

因为打印的日志是字面常量，没有计算逻辑。两段代码的性能是几乎一样的。添加isDebugEnabled反而会导致额外的代码。

原则二：如果有参数，且参数只是字符串常量或计算简单，使用占位符

考虑如下代码，debug方法包含了参数user.getName()。虽然执行debug方法时，会计算user.getName()，但只是一个简单的get方法，没有复杂计算，这时候，也可以不添加isDebugEnabled。

logger.debug("hello, {}", user.getName());

原则三：如果有参数，且参数计算复杂，添加isDebugEnabled 

logger.debug("order price: {}", calculatePrice());

假设calculatePrice方法需要经过复杂计算。那么就应该添加isDebugEnabled判断，使用如下的代码：

if(logger.isDebugEnabled()){
    logger.debug("order price: {}", calculatePrice());
}