你真的知道怎么使用Java日志API吗?
一、背景
在平时的开发过程中,常常看到一些编码不规范的打印日志的代码,这些代码虽然使用了日志API,却达不到预期的记录日志的目的,这正是我写本篇文章的背景原因。对于一些经验不足的开发人员来讲,他们可能会照猫画虎或者直接就使用日志API,只要代码不报错就行,往往不去理解API的含义,也没有系统学习底层原理。其实,我也是这样过来的。下面就从以下两个方面分享一些错误使用Java日志API的示例,一起学习避坑。
- 占位符的错误使用
- 异常日志的错误使用
二、Java日志API错误使用示例
1、占位符的错误使用示例
- 示例一:使用了占位符,却不给占位参数
// 使用了占位符,却对参数进行字符串拼接
Integer userId = 1001;
Long merchantId = 1000001234L;
// 输出结果为:创建订单请求参数:userId={}, merchantId={}10011000001234
log.info("创建订单请求参数:userId={}, merchantId={}" + userId + merchantId);
// 输出结果为:创建订单请求参数:userId={}1001, merchantId={}1000001234
log.info("创建订单请求参数:userId={}" + userId + ", merchantId={}" + merchantId);
// 使用了占位符,忘记给占位参数
// 输出结果即为原样输出
log.info("创建订单请求参数:userId={}, merchantId={}");
log.info("创建订单请求结果:orderId={}")
错误原因:以上代码实际使用到的是
/**
* Log a message at the INFO level.
*
* @param msg the message string to be logged
*/
public void info(String msg);
而不是
/**
* Log a message at the INFO level according to the specified format
* and arguments.
* <p/>
* <p>This form avoids superfluous string concatenation when the logger
* is disabled for the INFO level. However, this variant incurs the hidden
* (and relatively small) cost of creating an <code>Object[]</code> before invoking the method,
* even if this logger is disabled for INFO. The variants taking
* {@link #info(String, Object) one} and {@link #info(String, Object, Object) two}
* arguments exist solely in order to avoid this hidden cost.</p>
*
* @param format the format string
* @param arguments a list of 3 or more arguments
*/
public void info(String format, Object... arguments);
- 示例二:不使用占位符,却给占位参数
Integer userId = 1001;
Long merchantId = 1000001234L;
// 输出结果为:创建订单请求参数:userId=, merchantId=
// More arguments provided (2) than placeholders specified (0)
log.info("创建订单请求参数:userId=, merchantId=", userId, merchantId);
// 输出结果为:创建订单请求参数:userId=1001, merchantId=
// More arguments provided (2) than placeholders specified (1)
log.info("创建订单请求参数:userId={}, merchantId=", userId, merchantId);
不给占位符或占位符数量少于占位参数数量,这种情况多余的占位参数会不输出。
- 示例三:使用了占位符,占位参数数量与占位符数量不一致
Integer userId = 1001;
Long merchantId = 1000001234L;
// 输出结果为:创建订单请求参数:userId=1001, merchantId={}
// Fewer arguments provided (1) than placeholders specified (2)
log.info("创建订单请求参数:userId={}, merchantId={}", userId);
Long orderId = 100110000004321L;
// 输出结果为:创建订单请求结果:userId=1001, merchantId=1000001234
// More arguments provided (3) than placeholders specified (2)
log.info("创建订单请求结果:userId={}, merchantId={}", userId, merchantId, orderId);
占位参数比占位符少,则多余的占位符不被替换,原样输出;
占位参数比占位符多,则多余的占位参数不被输出。
- 正确示例:使用占位符,且占位参数数量与占位符数量保持一致
Integer userId = 1001;
Long merchantId = 1000001234L;
// 输出结果为:创建订单请求参数:userId=1001, merchantId=1000001234
log.info("创建订单请求参数:userId={}, merchantId={}", userId, merchantId);
Long orderId = 100110000004321L;
// 输出结果为:创建订单请求结果:userId=1001, merchantId=1000001234, orderId=100110000004321
log.info("创建订单请求结果:userId={}, merchantId={}, orderId={}", userId, merchantId, orderId);
2、异常日志的错误使用示例
- 示例一:仅输出异常信息,不输出异常堆栈
try {
Long orderId = createOrder(userId, merchantId);
int num = 666 / 0;
} catch (Exception e) {
// 输出结果为:创建订单失败:user=1001, msg=/ by zero
log.error("创建订单失败:user={}, msg={}", userId, e.getMessage());
}
这里不是说只输出异常信息就是一定不对的,只是不输出异常堆栈信息不便于排查与定位问题,建议尽量避免只输出异常信息。我曾经犯过这种错误,生产环境因为数据问题导致空指针异常,而异常信息中只能看到null,比如“创建订单失败:msg=null”。
- 示例二:输出异常堆栈,但却给占位符
try {
Long orderId = createOrder(userId, merchantId);
int num = 666 / 0;
} catch (Exception e) {
/* 输出结果为:
12:35:35.984 [main] ERROR stu.ljxcolin.logging.slf4j.Slf4jTests - 创建订单失败:user=1001, e={}
java.lang.ArithmeticException: / by zero
at stu.ljxcolin.logging.slf4j.Slf4jTests.test01(Slf4jTests.java:28)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
*/
log.error("创建订单失败:user={}, e={}", userId, e);
}
- 正确示例:输出异常堆栈信息,且throwable不需要给占位符
try {
Long orderId = createOrder(userId, merchantId);
int num = 666 / 0;
} catch (Exception e) {
/* 输出结果为:
12:35:35.984 [main] ERROR stu.ljxcolin.logging.slf4j.Slf4jTests - 创建订单失败:user=1001
java.lang.ArithmeticException: / by zero
at stu.ljxcolin.logging.slf4j.Slf4jTests.test01(Slf4jTests.java:28)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
*/
log.error("创建订单失败:user={}", userId, e);
}
// 请参见以下两个API
// public void error(String format, Object... arguments);
// public void error(String msg, Throwable t);
好了,Java日志API错误使用示例就分享完了。在我们使用Java日志API时需谨记:(1)使用占位符时要给占位参数,且占位符的数量要与占位参数的数量保持一致。(2)输出异常堆栈信息时,throwable不需要给占位符,把throwable放在最后一个参数。
三、推荐一个学习Java日志的项目
当然,只学习了如何正确使用日志API是不够的,下面介绍下我在学习各种日志框架过程中建立的一个Git仓库logging。该项目主要是对日志实现和日志门面进行了较全面的学习,包括日志的API、日志等级、日志格式以及日志配置文件的学习,还使用SpringBoot整合了Logback和Log4j2。大家可以参照该项目进行进一步的学习,也可以给该仓库提出建议或提交代码。仓库地址如下:
https://www.gitee.com/ljxcolin/logging.git。