AI 自动补全的这句日志能正常打印吗?

最近用上了 GitHub Copilot,它的能力不时让我惊叹,于是越来越多地面向 tab 编程,机械键盘的损耗都小了许多:-p

这天,它给我自动生成了一句像这样的日志打印代码:

1
2
3
4
5
try {
// ...
} catch (Exception e) {
log.error("Xxx 操作出错,订单号 {},操作人 {}", orderNumber, operatorName, e);
}

我盯着这行熟悉又陌生的代码——没错平时我自己也会这么写,但此时竟然产生了一丝不确定,它真的能按期望的效果,先打印出这句话,然后完整打印异常堆栈吗?

既然有疑惑,那就刨根问底一下。

为什么疑惑?

问了自己这个问题之后,我回想了一下,可能是因为以前遇到过这个:

如果最后一个参数不是 Throwable 类型,那 IDEA 会给出警告:

1
More arguments provided (3) than placeholders specified (2)

那为什么最后多出来的那个参数是 Throwable,IDE 就认为正常了呢?这就是本文要探索的问题。

消除疑惑

遇事不决,command + click 一下。可以看到方法的定义是这样的:

1
public void error(String format, Object... arguments);

可惜想看具体实现的时候发现实现类太多,索性写一个测试用例 debug 跟一下,一路 F7 进去(这里用的日志框架是 log4j2):

1
2
3
4
5
6
org.apache.logging.slf4j.Log4jLogger#error(java.lang.String, java.lang.Object...)
org.apache.logging.log4j.spi.AbstractLogger#logIfEnabled(java.lang.String, org.apache.logging.log4j.Level, org.apache.logging.log4j.Marker, java.lang.String, java.lang.Object...)
org.apache.logging.log4j.spi.AbstractLogger#logMessage(java.lang.String, org.apache.logging.log4j.Level, org.apache.logging.log4j.Marker, java.lang.String, java.lang.Object...)
org.apache.logging.log4j.message.ParameterizedMessageFactory#newMessage(java.lang.String, java.lang.Object...)
org.apache.logging.log4j.message.ParameterizedMessage#ParameterizedMessage(java.lang.String, java.lang.Object...)
org.apache.logging.log4j.message.ParameterizedMessage#init

秘密就在这里了:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
// org.apache.logging.log4j.message.ParameterizedMessage

private void init(final String messagePattern) {
this.messagePattern = messagePattern;
final int len = Math.max(1, messagePattern == null ? 0 : messagePattern.length() >> 1); // divide by 2
this.indices = new int[len]; // LOG4J2-1542 ensure non-zero array length
// 计算占位符个数
final int placeholders = ParameterFormatter.countArgumentPlaceholders2(messagePattern, indices);
initThrowable(argArray, placeholders);
this.usedCount = Math.min(placeholders, argArray == null ? 0 : argArray.length);
}

private void initThrowable(final Object[] params, final int usedParams) {
if (params != null) {
final int argCount = params.length;
// 如果占位符个数比参数个数少,且最后一个参数是 throwable 类型,
// 则将最后一个参数赋值给 Message 的成员
if (usedParams < argCount && this.throwable == null && params[argCount - 1] instanceof Throwable) {
this.throwable = (Throwable) params[argCount - 1];
}
}
}

然后在调用堆栈回溯几步有:

1
2
3
4
5
6
7
// org.apache.logging.log4j.spi.AbstractLogger

protected void logMessage(final String fqcn, final Level level, final Marker marker, final String message,
final Object... params) {
final Message msg = messageFactory.newMessage(message, params);
logMessageSafely(fqcn, level, marker, msg, msg.getThrowable());
}

至此基本上清晰了。

结论

经过分析及实际运行验证:

  • AI 生成的代码可以按期望效果打印;
  • 如果有比占位符多的非 Throwable 类型参数,会被忽略掉。