起因
前幾天一個跑有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包即可。
在移除后,我們再次重啟任務,發現這下日志又可以正常輸出了,至此算是解決了這個問題。