起因
前几天一个跑有java应用的生产集群(200多台物理机)升级了一个版本,重启后发现约有50台机器日志不能正常输出,但其程序确能正常的运行,在生产环境中,日志是非常重要的一个监控手段,如果没有日志输出,无疑是非常危险的。
排查
发现这一情况后,立即开始从jdk环境和版本,cpu负载,内存gc,线程stack,死锁,磁盘容量等多方面排查,但均没有发现异常情况,唯一的一点信息是Java进程重启时重定向到out文件里面的控制台输出,如下(以下均为复现时的输出):
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.3/log4j-slf4j-impl-2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/slf4j/slf4j-log4j12/1.7.12/slf4j-log4j12-1.7.12.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.apache.logging.slf4j.Log4jLoggerFactory]
起初并没有在意日志包冲突的这个细节,因为其他正常启动并能够正常打印log的机器中,也有同样的输出。所以基本肯定与这个冲突关系不大。
但苦于没有其他日志输出,并且当前的进程是在正常的Runnable状态中,所以又把目光回到了刚才的out文件,经过与正常机器中大部分out文件比较,发现了一点端倪。
(1)大多数能够正常打印log机器的out文件输出是:
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.3/log4j-slf4j-impl-2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/slf4j/slf4j-log4j12/1.7.12/slf4j-log4j12-1.7.12.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.apache.logging.slf4j.Log4jLoggerFactory]
(2)少部分正常打印log的机器和其他不打印log的机器的out文件输出是:
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/slf4j/slf4j-log4j12/1.7.12/slf4j-log4j12-1.7.12.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/qindongliang/.m2/repository/org/apache/logging/log4j/log4j-slf4j-impl/2.3/log4j-slf4j-impl-2.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]
对比上面两个输出文件中的第三行,第四行和最后一行,发现不同的机器有可能输出的不一样,另外一点能够得到的是正常的机器sfl4j binding最后一行都是一样的类:
org.apache.logging.slf4j.Log4jLoggerFactory
而少数正常和所有不正常的slf4j binding的类是:
org.slf4j.impl.Log4jLoggerFactory
解决
这明显是slf4j binding包冲突造成的,经过调查发现,前者是log4j2.x用的工厂实现类,而后者是兼容log4j1.x用的工厂类,他们分别位于:
log4j-slf4j-impl-2.3.jar
和
slf4j-log4j12-1.7.12.jar
这两个jar包中,都有各自的StaticLoggerBinder类,所以才造成了冲突,因为我们用的是log4j2的日志组件,所以解决的方法就是移除掉与其冲突的log4j 1.x的slf4j-log4j12-1.7.12.jar包即可。
在移除后,我们再次重启任务,发现这下日志又可以正常输出了,至此算是解决了这个问题。