现象:
service 本地运行正常, dev,test环境均报如下错误:
Caused by: java.lang.NoSuchMethodError: org.apache.logging.log4j.core.util.Loader.loadClass(Ljava/lang/String;)Ljava/lang/Class;
at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:497)
at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:623)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:136)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:118)
at org.apache.logging.log4j.core.impl.MutableLogEvent.getThrownProxy(MutableLogEvent.java:329)
at org.apache.logging.log4j.core.impl.Log4jLogEvent$LogEventProxy.<init>(Log4jLogEvent.java:900)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.serialize(Log4jLogEvent.java:688)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.createMemento(Log4jLogEvent.java:735)
at com.meituan.inf.xmdlog.XMDFileAppender.append(XMDFileAppender.java:219)
at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:447)
at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:432)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:416)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:402)
at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2011)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1884)
at org.apache.logging.slf4j.Log4jLogger.error(Log4jLogger.java:309)
at com.sankuai.meituan.waimai.thrift.feature.service.PoiSearchService.getPoiPic(PoiSearchService.java:246)
at com.sankuai.meituan.waimai.thrift.feature.service.PoiSearchService.fillPics(PoiSearchService.java:223)
at com.sankuai.meituan.waimai.thrift.feature.service.PoiSearchService.poiSearch(PoiSearchService.java:128)
at com.sankuai.meituan.waimai.thrift.feature.controller.PoiSearchController.search(PoiSearchController.java:62)
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:497)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
... 46 more
排查过程:
1.本地服务启动正常, 但是部署到dev后, 调用查询接口, 就报异常, 因此首先反应的是服务所在的环境有问题, 推测可能是包冲突问题
2.通过本地代码分析, 不存在log4j-core依赖的不同版本, org.apache.logging.log4j.core.util.Loader在idea中,idea中搜索也只有一个类, 并且我们的服务是内置容器的,所以如果是容器环境引起的, 那么本地应该也是跑不通的.所以继而推断应该不是冲突问题, 但是从异常来看,就是冲突问题
3.通过mvn dependency:tree > denpendency.txt 分析依赖树, 通过Fusion Analyzer分析冲突关系
4.通过download下dev环境的包, 与本地的包进行对比, 发现log4j-core的包两边是一致, 版本也一致, 反编译出来的内容也一致, 所以大概率上不存在找不到的情况.
5.查看maven的settings.xml文件, 想确定是否是因为仓库不一致导致的某些包虽然名字相同,但内容不同. 发现, dev与线下使用的是同一个maven仓库
6.本地debug具体的代码逻辑, 通过一步步比对调用栈, 分析发现, 异常的触发是由于调用getWmPoiAggreByWmPoiIdWithSpecificField接口获取图片的接口抛出的(先不讨论这个接口异常是否合理),
被catch后,实际上抛出致命异常的是:
public String getPoiPic(Long poiId) {
if (null == poiId || poiId <= 0) {
return null;
}
HashSet<String> fields = new HashSet<>(1);
fields.add(WmPoiFieldQueryConstant.WM_POI_FIELD_PIC_URL);
try {
Long startTime = System.currentTimeMillis();
// 异常的触发点, 会被catch
WmPoiAggre poiAggre = wmPoiQueryThriftService.getWmPoiAggreByWmPoiIdWithSpecificField(poiId, fields);
Long endTime = System.currentTimeMillis();
log.info("获取商户ID:{} 图片耗时:{}", poiId, endTime - startTime);
if (null != poiAggre && StringUtils.isNotEmpty(poiAggre.getPic_url())) {
return poiAggre.getPic_url();
}
} catch (Exception e) {
// 真正异常的原因, 因为找不到类
log.error("获取商家图片出错, poiId:{}", poiId, e);
}
return null;
}
虽然异常很清晰, 但是始终没找到具体为什么会异常的原因.
7.继续走调用栈, 发现这一行开始, 本地调用栈和dev环境的调用栈就不一致了, 说明它们确实是调用了两个不同的类.
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:118)
8.通过搜索ThrowableProxy类, 发现,存在两个类信息, 这是冲突的很重要的特征. 正确的情况下,我们需要加载log4j-core的依赖中的ThrowableProxy类, 但是实际上加载了es 5.0.1中的ThrowableProxy. 根据推断,对比了下dev环境中的异常调用栈,
发现的确与es包中的ThrowableProxy调用点吻合.说明就是这个异常引起的.
9.找到原因了, 对于解决包冲突,正常的思路是排除不同版本的包, 只留下一个版本. 但是对于这种es中将log4j-core直接拷进去,再改改的骚操作, 排包就没啥用了. 只能进行替换es版本. 这里会存在一个问题是,如果工程强制要用es5.0.1, 就会引起调用的冲突,这个是不好解决的
10.对于为什么本地运行没有异常, dev环境上运行有异常, 可能的原因是本地和dev环境对于加载ThrowableProxy的顺序不一致导致的. jvm只会加载一次限定名一样的类(包名+类名)
总结:
首先,包冲突的现象千变万化, 感觉每次都能遇到新的现象. 其次是通过这次排包,感受最深的是, 调用栈的分析十分关键.