记一次上线遇到的jar包依赖冲突问题

周四夜间例行发版，我因有事先回家。

夜间10点半，看到讨论组里说zhenghe-channel工程里的channel-provider和channel-web两个服务发版出现问题，看错误是配置中间件Apollo导致的。后来在洲、李干两同学把apollo的jar包排除掉，又出现了新的问题。错误为：java.lang.IllegalArgumentException: LoggerFactory is not a Logback LoggerContext but Logback is on the classpath. Either remove Logback or the competing implementation (class org.slf4j.impl.Log4jLoggerFactory loaded from jar:file:/www/service/channel-provider/channel-provider.jar!/BOOT-INF/lib/slf4j-log4j12-1.7.25.jar!/).  而奇怪的是，本地和测试环境却不存在这个问题。时间到了午夜12点，生产环境的这个问题仍然没有fix，鉴于本次zhenghe-channel的上线内容比较少，就先回滚了事。

 

周五下午，我们找时间来继续排查这个问题。功夫不负有心人！

 

先说说项目间的依赖关系。如下图，zhenghe-channel工程的channel-provider和channel-web依赖了zhenghe-base工程的zhenghe-common，zhenghe-common里依赖了apollo-client和spring-cloud-context。另外，程序发版是通过Jenkins实现程序的打包和服务的部署，测试环境的Jenkins&maven与生产环境的Jenkins&maven在两台不同的机器上。

 

 

周四发版时一开始启动服务的报错信息如下，这个问题是因为zhenghe-channel的这两个服务尚未接入Apollo配置中心，在application.yml文件里没有apollo的配置。解决办法是在pom.xml文件里排除ctrip.framework.apollo和spring-cloud-context包。

INFO 2021-11-11 22:33:33:031 main SnifferConfigInitializer : Config file found in /opt/apache-skywalking-apm-bin-es7/agent/config/agent.config.
SLF4J: Class path contains multiple SLF4J bindings.
...
Exception in thread "main" java.lang.reflect.InvocationTargetException
        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.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:50)
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:51)
Caused by: java.lang.IllegalArgumentException: Cannot instantiate interface org.springframework.context.ApplicationContextInitializer : 
com.ctrip.framework.apollo.spring.boot.ApolloApplicationContextInitializer
        at org.springframework.boot.SpringApplication.createSpringFactoriesInstances(SpringApplication.java:450)
        at org.springframework.boot.SpringApplication.getSpringFactoriesInstances(SpringApplication.java:429)
        at org.springframework.boot.SpringApplication.getSpringFactoriesInstances(SpringApplication.java:420)
        at org.springframework.boot.SpringApplication.<init>(SpringApplication.java:268)
        at org.springframework.boot.SpringApplication.<init>(SpringApplication.java:249)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248)
        at com.emax.channel.provider.ServerApplication.main(ServerApplication.java:32)
        ... 8 more
Caused by: org.springframework.beans.BeanInstantiationException: 
Failed to instantiate [com.ctrip.framework.apollo.spring.boot.ApolloApplicationContextInitializer]: 
Constructor threw exception; nested exception is com.ctrip.framework.apollo.exceptions.ApolloConfigException: 
Unable to load instance for com.ctrip.framework.apollo.spring.config.ConfigPropertySourceFactory!
        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:184)
        at org.springframework.boot.SpringApplication.createSpringFactoriesInstances(SpringApplication.java:446)
        ... 15 more
Caused by: com.ctrip.framework.apollo.exceptions.ApolloConfigException: 
Unable to load instance for com.ctrip.framework.apollo.spring.config.ConfigPropertySourceFactory!
        at com.ctrip.framework.apollo.spring.util.SpringInjector.getInstance(SpringInjector.java:40)
        at com.ctrip.framework.apollo.spring.boot.ApolloApplicationContextInitializer.<init>(ApolloApplicationContextInitializer.java:48)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:172)
        ... 16 more
Caused by: com.ctrip.framework.apollo.exceptions.ApolloConfigException: Unable to initialize Apollo Spring Injector!
        at com.ctrip.framework.apollo.spring.util.SpringInjector.getInjector(SpringInjector.java:24)
        at com.ctrip.framework.apollo.spring.util.SpringInjector.getInstance(SpringInjector.java:37)
        ... 22 more
Caused by: java.lang.NoSuchMethodError: com.google.common.base.Preconditions.checkState(ZLjava/lang/String;Ljava/lang/Object;)V
        at com.google.common.cache.CacheBuilder.setKeyStrength(CacheBuilder.java:536)
        at com.google.common.cache.CacheBuilder.weakKeys(CacheBuilder.java:532)
        at com.google.inject.internal.WeakKeySet.<init>(WeakKeySet.java:56)
        at com.google.inject.internal.InheritingState.<init>(InheritingState.java:67)
        at com.google.inject.internal.InjectorShell$Builder.getState(InjectorShell.java:209)
        at com.google.inject.internal.InjectorShell$Builder.lock(InjectorShell.java:115)
        at com.google.inject.internal.InternalInjectorCreator.build(InternalInjectorCreator.java:103)
        at com.google.inject.Guice.createInjector(Guice.java:99)
        at com.google.inject.Guice.createInjector(Guice.java:73)
        at com.google.inject.Guice.createInjector(Guice.java:62)
        at com.ctrip.framework.apollo.spring.util.SpringInjector.getInjector(SpringInjector.java:22)
        ... 23 more

 

接下来再启动服务出现的错误是LoggerFactory is not a Logback LoggerContext but Logback is on the classpath. 异常堆栈如下。大致意思是：由于项目使用的日志框架是logback，而容器启动时发现存在log4j的LoggerFactory，异常message里提到了slf4j-log4j12-1.7.25.jar这个包。然后，我们找运维确认，发现生产环境的程序部署包的lib下果然存在这个slf4j-log4j12-1.7.25.jar，并且，将其删掉后，服务是可以正常启动的。

INFO 2021-11-11 22:54:30:247 main SnifferConfigInitializer : Config file found in /opt/apache-skywalking-apm-bin-es7/agent/config/agent.config.
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/www/service/channel-provider/channel-provider.jar!/BOOT-INF/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/www/service/channel-provider/channel-provider.jar!/BOOT-INF/lib/slf4j-simple-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/www/service/channel-provider/channel-provider.jar!/BOOT-INF/lib/logback-classic-1.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]
log4j:WARN No appenders could be found for logger (org.springframework.core.KotlinDetector).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
Exception in thread "main" java.lang.reflect.InvocationTargetException
        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.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:50)
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:51)
Caused by: java.lang.IllegalArgumentException: LoggerFactory is not a Logback LoggerContext but Logback is on the classpath. 
Either remove Logback or the competing implementation (class org.slf4j.impl.Log4jLoggerFactory loaded 
from jar:file:/www/service/channel-provider/channel-provider.jar!/BOOT-INF/lib/slf4j-log4j12-1.7.25.jar!/). 
If you are using WebLogic you will need to add 'org.slf4j' to prefer-application-packages in WEB-INF/weblogic.xml: org.slf4j.impl.Log4jLoggerFactory
        at org.springframework.util.Assert.instanceCheckFailed(Assert.java:655)
        at org.springframework.util.Assert.isInstanceOf(Assert.java:555)
        at org.springframework.boot.logging.logback.LogbackLoggingSystem.getLoggerContext(LogbackLoggingSystem.java:286)
        at org.springframework.boot.logging.logback.LogbackLoggingSystem.beforeInitialize(LogbackLoggingSystem.java:102)
        at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationStartingEvent(LoggingApplicationListener.java:220)
        at org.springframework.boot.context.logging.LoggingApplicationListener.onApplicationEvent(LoggingApplicationListener.java:199)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)
        at org.springframework.boot.context.event.EventPublishingRunListener.starting(EventPublishingRunListener.java:69)
        at org.springframework.boot.SpringApplicationRunListeners.starting(SpringApplicationRunListeners.java:48)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:302)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260)
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248)
        at com.emax.channel.provider.ServerApplication.main(ServerApplication.java:32)
        ... 8 more

 

那么，显然，问题就在于多出的这个slf4j-log4j12-1.7.25.jar。是哪里依赖它了呢？

因为在本地计算机使用maven的dependency:tree证实项目并不存在对slf4j-log4j12-1.7.25.jar的依赖，测试环境Jenkins通过maven打包也不存在slf4j-log4j12-1.7.25.jar，并且服务能正常启动，再加上近期对zhenghe-channel的开发并不涉及pom的改动，再加上近期各项目在逐步集成apollo配置中心，所以大家的怀疑点还是apollo，认为是apollo导致的这个错误。

究竟是不是呢？

答案是：否！

在apollo涉及的apollo-client和spring-cloud-context这两个包的pom里，并未发现对slf4j-log4j12-1.7.25.jar的依赖。

我将分析点定位在生产Jenkins机器上的maven仓库，是不是有些包的版本跟本地maven仓库的不同呢。为了求证，我将maven的dependency:tree命令交给运维，运维临时将Jenkins构建任务的clean install改成这个dependency:tree，然后再build， 发现是一个cncb-pay-sdk-core.jar依赖了slf4j-log4j12-1.7.25.jar。  cncb-pay-sdk-core是zhenghe-channel里的一个module，build后是一个本地jar，并且在Jenkins上存在cncb-pay-sdk-core的构建任务。 重新构建这个cncb-pay-sdk-core任务，然后回来在构建channel-provider或channel-web时，发现服务正常启动！那个可恶的slf4j-log4j12-1.7.25.jar终于给消灭掉了！