日志中记录Java异常信息
遇到的问题
今天遇到一个线上的BUG,在执行表单提交时失败,但是从程序日志中看不到任何异常信息。
在Review源代码时发现,当catch到异常时只是输出了e.getMessage(),如下所示:
1
|
logger.error( "error: {}, {}" , params, e.getMessage());
|
在日志中看不到任何信息,说明e.getMessage()返回值为空字符串。
原因分析
先来看一下Java中的异常类图:
Throwable是Java中所有异常信息的*父类,其中的成员变量detailMessage就是在调用e.getMessage()返回的值。
那么这个属性会在什么时候赋值呢,追溯源码发现,该属性只会在Throwable构造函数中赋值。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
|
public Throwable() {
// 在默认构造函数中不会给detailMessage属性赋值
fillInStackTrace();
}
public Throwable(String message) {
fillInStackTrace();
// 直接将参数赋值给detailMessage
detailMessage = message;
}
public Throwable(String message, Throwable cause) {
fillInStackTrace();
// 直接将参数赋值给detailMessage
detailMessage = message;
this .cause = cause;
}
public Throwable(Throwable cause) {
fillInStackTrace();
// 当传入的Throwable对象不为空时,为detailMessage赋值
detailMessage = (cause== null ? null : cause.toString());
this .cause = cause;
}
protected Throwable(String message, Throwable cause,
boolean enableSuppression,
boolean writableStackTrace) {
if (writableStackTrace) {
fillInStackTrace();
} else {
stackTrace = null ;
}
// 直接将参数赋值给detailMessage
detailMessage = message;
this .cause = cause;
if (!enableSuppression)
suppressedExceptions = null ;
}
|
显然,从源码中可以看到在Throwable的默认构造函数中是不会给detailMessage属性赋值的。
也就是说,当异常对象是通过默认构造函数实例化的,或者实例化时传入的message为空字符串,那么调用getMessage()方法时返回值就为空,也就是我遇到的情形。
所以,在程序日志中不要单纯使用getMessage()方法获取异常信息(返回值为空时,不利于问题排查)。
正确的做法
在Java开发中,常用的日志框架及组件通常是:slf4j,log4j和logback,他们的关系可以描述为:slf4j提供了统一的日志API,将具体的日志实现交给log4j与logback。
也就是说,通常我们只需要在项目中使用slf4j作为日志API,再集成log4j或者logback即可。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
<!-- 使用slf4j作为日志API -->
< dependency >
< groupId >org.slf4j</ groupId >
< artifactId >slf4j-api</ artifactId >
< version >1.7.25</ version >
</ dependency >
<!-- 集成logback作为具体的日志实现 -->
< dependency >
< groupId >ch.qos.logback</ groupId >
< artifactId >logback-core</ artifactId >
< version >1.2.3</ version >
</ dependency >
< dependency >
< groupId >ch.qos.logback</ groupId >
< artifactId >logback-classic</ artifactId >
< version >1.2.3</ version >
</ dependency >
|
上述配置以集成slf4j和logback为例,添加对应的logback配置文件(logback.xml):
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
< configuration scan = "false" scanPeriod = "30 seconds" debug = "false" packagingData = "true" >
< statusListener class = "ch.qos.logback.core.status.OnConsoleStatusListener" />
<!-- 输出到控制台 -->
< appender name = "STDOUT" class = "ch.qos.logback.core.ConsoleAppender" >
< encoder >
< pattern >%date %level [%thread] %logger{10} [%file:%line] %msg%n</ pattern >
</ encoder >
</ appender >
<!-- 输出到文件 -->
< appender name = "FILE" class = "ch.qos.logback.core.FileAppender" >
< file >test.log</ file >
< encoder >
< pattern >%date %level [%thread] %logger{10} [%file:%line] %msg%n</ pattern >
</ encoder >
</ appender >
< root level = "info" >
< appender-ref ref = "STDOUT" />
< appender-ref ref = "FILE" />
</ root >
</ configuration >
|
在Java中通过slf4j提供的日志API记录日志:
1
2
3
4
5
|
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Test {
private static final Logger logger = LoggerFactory.getLogger(Test. class );
}
|
当我们需要在程序日志中输出异常信息时,应该直接传入异常对象即可,而不要单纯通过异常对象的getMessage()方法获取输出异常信息。
1
2
3
4
5
6
7
8
9
10
|
public void test() {
try {
// 使用默认构造函数实实例化异常对象
throw new NullPointerException();
} catch (Exception e) {
// 直接将异常对象传入日志接口,保存异常信息到日志文件中
logger.error( "error: {}" , e.getMessage(), e);
e.printStackTrace();
}
}
|
如下是保存到日志文件中的异常信息片段:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
2019 - 06 - 20 20 : 04 : 25 , 290 ERROR [http-nio- 8090 -exec- 1 ] o.c.s.f.c.TestExceptionController [TestExceptionController.java: 26 ] error: null # 使用默认构造参数实例化异常对象时,getMessage()方法返回值为空对象
# 如下是具体的异常堆栈信息
java.lang.NullPointerException: null
at org.chench.springboot.falsework.controller.TestExceptionController.test(TestExceptionController.java: 24 ) ~[classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na: 1.8 .0_181]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: 62 ) ~[na: 1.8 .0_181]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java: 43 ) ~[na: 1.8 .0_181]
at java.lang.reflect.Method.invoke(Method.java: 498 ) ~[na: 1.8 .0_181]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java: 209 ) [spring-web- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java: 136 ) [spring-web- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java: 102 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java: 877 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java: 783 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java: 87 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java: 991 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java: 925 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java: 974 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java: 866 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java: 635 ) [tomcat-embed-core- 8.5 . 31 .jar: 8.5 . 31 ]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java: 851 ) [spring-webmvc- 5.0 . 6 .RELEASE.jar: 5.0 . 6 .RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java: 742 ) [tomcat-embed-core- 8.5 . 31 .jar: 8.5 . 31 ]
......
|
java异常在控制台和日志里面的打印记录
1、e.printStackTrace()打印在哪里
在catch中的e.printStackTrace()将打印到控制台
2、e.printStackTrace()打印的内容是什么
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
import org.apache.logging.log4j.Logger;
public class ExceptionTest {
private static final Logger logger=LogManager.getLogger();
public void test() {
try {
int i= 1 / 0 ;
} catch (Exception e){
e.printStackTrace();
}
}
public static void main(String[] args) {
ExceptionTest test= new ExceptionTest();
test.test();
}
}
|
输出结果如下:
java.lang.ArithmeticException: / by zero
at myProject.ExceptionTest.test(ExceptionTest.java:10)
at myProject.ExceptionTest.main(ExceptionTest.java:18)
可见,e.printStackTrace()打印了错误的具体信息,即这个错误出现的位置,便于查找错误源
3、如果将e.printStackTrace()的信息打印在日志里应该怎么做呢?
见如下代码:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
package myProject;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class ExceptionTest {
private static final Logger logger=LogManager.getLogger();
public void test() {
try {
int i= 1 / 0 ;
} catch (Exception e){
logger.error(e);
}
}
public static void main(String[] args) {
ExceptionTest test= new ExceptionTest();
test.test();
}
}
|
用logger.error(e);打印日志,输出结果如下:
19:17:39.753 [main] ERROR myProject.ExceptionTest - java.lang.ArithmeticException: / by zero
可见,用这种方法打印的日志,只有大概的错误信息,并没有指出报错的代码位置,不便于查找错误。用logger.error(e.getMessage());也是输出这种大概的错误信息。
再见如下代码:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
package myProject;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class ExceptionTest {
private static final Logger logger=LogManager.getLogger();
public void test() {
try {
int i= 1 / 0 ;
} catch (Exception e){
logger.error( "ExceptionTest Exception:" ,e);
}
}
public static void main(String[] args) {
ExceptionTest test= new ExceptionTest();
test.test();
}
}
|
用logger.error("ExceptionTest Exception:",e);,则输出结果如下:
9:20:32.948 [main] ERROR myProject.ExceptionTest - ExceptionTest Exception:
java.lang.ArithmeticException: / by zero
at myProject.ExceptionTest.test(ExceptionTest.java:10) [classes/:?]
at myProject.ExceptionTest.main(ExceptionTest.java:18) [classes/:?]
这和e.printStackTrace()打印的内容大致是相同的。不过最好,还是使用logger.error(e.getMessage(),e)方法来在日志上查看异常的详细结果
以上为个人经验,希望能给大家一个参考,也希望大家多多支持服务器之家。
原文链接:https://jingzh.blog.csdn.net/article/details/81410992