背景
最近同事在对项目Jersey由1.6升级至2.X,本地测试一切顺利。但是当部署到INT环境后,发现后台异步线程执行途中就消失了。其伪代码如下:
public static void exec() {
LOG.info("begin start");
try {
//do business code
LOG.info("finish business");
} catch (Exception e) {
LOG.error("exception ", e);
throw e;
} finally {
LOG.info("finally");
//do
}
}
现象
在输出日志中,可以看到:
begin start
没有finish business的日志输出,也没有打印出catch块中的Exception信息。
查找原因
从日志上无法看出任何有用信息,只能知道线程在执行业务逻辑时,中断执行跳出。本来准备用jstack查看一下线程执行时候场景,但是前几天看到阿里开源了arthas工具,就拿过来牛刀小试一把。
安装和监控
安装完成后,用trace来跟踪具体的调用链路(具体请见arthas的官方文档)。
$ trace com....platform.file.client.FileServiceClient createFileMetadata
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 228 ms.
`---ts=2019-01-11 07:34:48;thread_name=async.impl.MessageReceiverExecutor-19(queue@xxxRunReportQueue)-5;id=b9;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@764c12b6
`---[0.769619ms] com....platform.file.client.FileServiceClient:createFileMetadata()
+---[0.383598ms] com....platform.file.client.FileManagementClient:createFileMetadata() [throws Exception]
`---[0.005124ms] throw:java.lang.NoSuchMethodError()
`---[0.005124ms] throw:java.lang.NoSuchMethodError()
可见根本原因是:NoSuchMethodError。但是到底是哪个Class的方法没有呢?可惜没有打印出来。我们继续查看调用链上的方法:
$ trace org.glassfish.jersey.client.ClientRequest accept
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:2) cost in 222 ms.
`---ts=2019-01-11 09:42:52;thread_name=async.impl.MessageReceiverExecutor-19(queue@xxReportQueue)-39;id=1dc;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@764c12b6
`---[0.29744ms] org.glassfish.jersey.client.ClientRequest:accept()
+---[0.024457ms] org.glassfish.jersey.client.ClientRequest:getHeaders()
+---[0.114488ms] javax.ws.rs.core.MultivaluedMap:addAll() [throws Exception]
`---[8.08E-4ms] throw:java.lang.NoSuchMethodError()
可以看到MultivaluedMap,缺少addAll方法。查看该类在javax.ws.rs.core的Jar包中,且出现了两个版本。在INT环境,加载了低版本的Class导致出现该异常。
使用Jar包检测工具
有很多的检测工具、脚本,可以检测class的重复,多个版本。这里不再重复。
让错误信息暴露出来
让LOG记录这类关键信息,以方便我们定位。
我们看到在Java NoSuchMethodError文档中标明:出现这类错误,是系统出现了不合理的严重问题,该问题应该在编译的时候就发现,应用中不应catch这类错误,应当暴露出来。
但是,在这里由于是异步线程,出现该错误没有任何的日志打印记录,无法显示的暴露问题, 建议 catch (Throwable e), 记录日志,然后将异常抛出。如下:
public static void exec() {
try {
//do business
} catch (Throwable e) {
LOG.error("exception ", e);
throw e;
} finally {
}
}
结论
项目需要保持各种JAR包版本的干净,用工具来进行检测。且在代码中,我们要尽可能的将这种异常记录出来,以方便定位。