应用从 jdk7 升级到 jdk8,终于可以用上新特性的语法进行代码编写,通过几轮开发、测试和验证后,在上预发环境时,应用突然无法启动,查看 tomcat 报错原因,发现是 类转换失败 ClassCastException
报错原因
Class path contains multiple SLF4J binding
23-May-2019 16:04:25.300 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/admin/xxx/WEB-INF/lib/slf4j-log4j12-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/admin/xxx/WEB-INF/lib/logback-classic-1.1.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
报错原因
org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext
org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘cn.com.xxx.framework.log.integration.LogbackInitializer#0’ defined in class path resource [spring/spring-log-init.xml]: Invocation of init method failed; nested exception is java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext
…
Caused by: java.lang.ClassCastException: org.slf4j.impl.Log4jLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext
# 出问题的加载地方
at ch.qos.logback.ext.spring.LogbackConfigurer.initLogging(LogbackConfigurer.java:72)
at cn.com.xxx.framework.log.integration.LogbackInitializer.init(LogbackInitializer.java:49)
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.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1706)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1645)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1574)
… 26 more
23-May-2019 15:59:12.398 SEVERE [localhost-startStop-1] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
查看报错代码
public static void initLogging(String location) throws FileNotFoundException, JoranException {
String resolvedLocation = SystemPropertyUtils.resolvePlaceholders(location);
URL url = ResourceUtils.getURL(resolvedLocation);
LoggerContext loggerContext = (LoggerContext)StaticLoggerBinder.getSingleton().getLoggerFactory();
loggerContext.reset();
new ContextInitializer(loggerContext).configureByResource(url);
}
可以看到,通过 StaticLoggerBinder.getSingleton().getLoggerFactory()
获取 logger 上下文这段代码报错了,通过仔细定位,发现了有两个 StaticLoggerBinder
类
更重要的是,他们两兄弟竟然虽然不是同一个 jar 包,但是包路径和名称都一模一样!!!
由于我们需要的是 logback
包,而不是 slf4j-log4j12
包,所以需要排除掉 slf4j-log4j12
依赖。
详细:Maven从入门到放弃
解决方法
① 通过 POM 文件排查包冲突
② 安装 IDEA 的插件 Maven Helper
③ 定位到编译 WAR 包的 POM 文件(我们框架定义的在 Deploy 模块中)
④ 在搜索框中,输入搜索内容,点击右键可以看到选项框
-
Jump To Source(跳转到源文件处)
-
Exclude(排除掉)
例如我点击了 Exclude
,就能看到 pom 文件中,这个依赖就被排除掉了
cn.com.xxx
framework-conf-client
${xqy.framework.version}
slf4j-log4j12
org.slf4j
排除依赖后,提交代码,重新打包,部署一条龙,顺利启动~
思考
–
包冲突解决是简单的,通过 maven 插件可以精确找到依赖,然后进行 Exclude,可是在本地开发、测试环境都没有出现的问题,却在预发环境出现了,所以排除了业务逻辑代码的原因,简单考虑了几个因素和原因:
-
jdk 版本
-
tomcat 版本
-
类加载机制
-
第三方 jar 互相依赖
由于 jdk 和 tomcat 这两者没有明显的报错原因,所以先去排查类的加载机制
类加载机制
复习一下类加载机制
我们写的 Java 应用代码,一般是通过 App ClassLoader
应用加载器进行加载,它不会自己先去加载它,而是通过 Extension ClassLoader
扩展类加载器进行加载(其中扩展类加载器又会去找 Bootstrap ClassLoader
启动类加载器进行加载),只有父加载器无法加载情况下,才会让下级加载器进行加载。
引用自zthgreat
★
当一个ClassLoader实例需要加载某个类时,它会试图亲自搜索某个类之前,先把这个任务委托给它的父类加载器,这个过程是由上至下依次检查的,首先由最顶层的类加载器Bootstrap ClassLoader试图加载,如果没加载到,则把任务转交给Extension ClassLoader试图加载,如果也没加载到,则转交给App ClassLoader 进行加载,如果它也没有加载得到的话,则返回给委托的发起者,由它到指定的文件系统或网络等URL中加载该类。如果它们都没有加载到这个类时,则抛出ClassNotFoundException异常。
”
ClassLoader
Java 使用的是双亲委派加载机制,通过查看 ClassLoader
类,可以对此有所了解。
类被成功加载后,将被放入到内存中,内存中存放 Class 实例对象。
protected Class<?> loadClass(String name, boolean resolve)
throws ClassNotFoundException
{
synchronized (getClassLoadingLock(name)) {
// First, check if the class has already been loaded
// 首先,检查 class 是否已经被加载
Class<?> c = findLoadedClass(name);
if (c == null) {
// 如果没有被加载
long t0 = System.nanoTime();
try {
if (parent != null) {
// 寻找 parent 加载器
c = parent.loadClass(name, false);
} else {
// 如果父加载器不存在,则委托给启动类加载器加载
c = findBootstrapClassOrNull(name);
}
} catch (ClassNotFoundException e) {
// ClassNotFoundException thrown if class not found
// from the non-null parent class loader
}
if (c == null) {
// If still not found, then invoke findClass in order
// to find the class.
// 如果仍然无法加载,才会尝试自身加载
long t1 = System.nanoTime();
c = findClass(name);
// this is the defining class loader; record the stats
sun.misc.PerfCounter.getParentDelegationTime().addTime(t1 - t0);
sun.misc.PerfCounter.getFindClassTime().addElapsedTimeFrom(t1);
sun.misc.PerfCounter.getFindClasses().increment();
}
}
if (resolve) {
resolveClass©;
}
return c;
}
}
类加载顺序
从代码中了解到,如果某个名字的类被加载后,类加载器是不会再重新加载,所以我们的问题根本原因可以是出现在:
先加载了 org.slf4j
包的 org.slf4j.impl.StaticLoggerBinder
,同名的 ch.qos.logback
包下的 StaticLoggerBinder
类没有被加载
通过查阅文章:
★
跟JAR文件的文件名有关。按照字母的顺序加载JAR文件。有了这个类以后,后面的类则不会加载了。
jvm 加载包名和类名相同的类时,先加载classpath中jar路径放在前面的,包名类名都相同,那jvm没法区分了,如果使用ide一般情况下是会提示发生冲突而报错,若不报错,只有第一个包被引入(在classpath路径下排在前面的包),第二个包会在classloader加载类时判断重复而忽略。
”
查看加载顺序
在 jvm 启动脚本中,添加 -verbose
参数或者 -XX:+TraceClassLoading
[Loaded java.lang.CloneNotSupportedException from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.lang.Thread$State from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$NavigableSubMap from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap$AscendingSubMap from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap N a v i g a b l e S u b M a p NavigableSubMap NavigableSubMapEntrySetView from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap A s c e n d i n g S u b M a p AscendingSubMap AscendingSubMapAscendingEntrySetView from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap N a v i g a b l e S u b M a p NavigableSubMap NavigableSubMapSubMapIterator from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
[Loaded java.util.TreeMap N a v i g a b l e S u b M a p NavigableSubMap NavigableSubMapSubMapEntryIterator from /Users/jingqi/.jrebel/bootcache/jrebel-bootstrap-89f567048120ef32b965233b5ba2f7ca.jar]
之前在本地开发中,IDEA 优化先加载了 ch.qos.logback
的 StaticLoggerBinder
类,然后后面的 org.slf4j
包下的同名类就没有被加载。
但这样也有个不明白,按理说加载顺序按照字母顺序加载,预发环境还是能够跟本地开发一样,加载到我们需要的类。实际上,加载器加载到的是另一个类,导致应用无法启动。
通过查找资料
★
问题就是jar的加载顺序问题,而这个顺序实际上是由文件系统决定的,linux内部是用inode来指示文件的。
这种储存文件元信息的区域就叫做inode,中文译名为”索引节点”。每一个文件都有对应的inode,里面包含了与该文件有关的一些信息。
Unix/linux系统内部不使用文件名,而使用inode号码来识别文件。对于系统来说,文件名只是inode号码便于识别的别称或者绰号。
”
为了验证 inode
是否是问题的原因,我做了以下测试:
inode 测试加载顺序
本地 Tomcat8 测试(正常启动)
将之前在 uat 环境有问题的代码版本重新打包,不使用 idea 工具,直接用 tomcat8 启动,并且在 catalina.sh
脚本中加入类加载打印参数 -XX:+TraceClassLoading