【从零单排】详解 Log4j + Slf4j 等日志框架(下篇)
上篇
- 首先,本文会简单介绍日志框架是什么。
- 其次,本文会讲解 JUL + JCL + Log4j + Slf4j 等如何实际使用。
下篇
- 然后,本文会探讨当项目中不同 jar 包使用不同日志框架时的兼容性问题。
- 最后,本文会介绍一个关于日志框架的实际 Debug 的例子。
桥接
如果使用了多个 log framework,可以使用桥接的方法,把 log_framework_a 的日志 “转” 到 log_framework_b 输出。常见的几个桥接的包如下:
log4j1 to log4j2
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-1.2-api</artifactId>
<version>2.2</version>
</dependency>
log4j2 to slf4j
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-to-slf4j</artifactId>
<version>2.2</version>
</dependency>
slf4j to log4j1
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.7.25</version>
</dependency>
slf4j to log4j2
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.2</version>
</dependency>
详见 https://logging.apache.org/log4j/log4j-2.2/log4j-1.2-api/index.html
兼容性 - 问题
在实际项目中,很可能存在多种日志框架。比如:自己的应用使用了 Log4j ,而引入的依赖分别使用了 Log4j2 和 Slf4j 。
MyApp -> Log4j
-> RefJar1 -> Log4j2
-> RefJar2 -> Slf4j
如果配置得不对,一个常见的报错信息如下:
ERROR StatusLogger No Log4j 2 configuration file found.
Using default configuration (logging only errors to the console),
or user programmatically provided configurations. Set system property 'log4j2.debug' to show Log4j 2 internal initialization logging.
See https://logging.apache.org/log4j/2.x/manual/configuration.html for instructions on how to configure Log4j 2
并且,可能应用启动不起来,或者日志没有正确输出。
兼容性 - 解决1
现在,我尝试模拟兼容性问题,首先,准备三个不同的类分别使用不同的 Log 框架。
模块1:Log4j2Module.java
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;
public class Log4j2Module {
static Logger log = LogManager.getLogger(Log4j2Module.class);
public void call() {
log.debug("Debug");
log.info("Info");
log.error("Error");
}
}
模块2:Log4jModule.java
import org.apache.log4j.Logger;
public class Log4jModule {
static Logger log = Logger.getLogger(Log4jModule.class);
public void call() {
log.debug("Debug");
log.info("Info");
log.error("Error");
}
}
模块3:Slf4jModule.java
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Slf4jModule {
private static final Logger log = LoggerFactory.getLogger(Slf4jModule.class);
public void call() {
log.debug("Debug");
log.info("Info");
log.error("Error");
}
}
最后,统一调用它们。
public class MultiLoggersApp {
public static void main(String[] args) {
Log4j2Module m1 = new Log4j2Module();
Log4jModule m2 = new Log4jModule();
Slf4jModule m3 = new Slf4jModule();
m1.call();
m2.call();
m3.call();
}
}
为了使上述工作,我需要正确设置"依赖"和"配置"。
一种方案是:
- Log4j2 使用
log4j2.xml
,输出一份到对应文件 - Log4j 使用
log4j.properties
,输出一份到对应文件 - Slf4j 搭配 Log4j2 ,输出一份到对应文件
基于此,"依赖"设置如下:
<!-- log4j -->
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>1.2.17</version>
</dependency>
<!-- log4j2 -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.11.1</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.11.1</version>
</dependency>
<!-- slf4j -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.25</version>
</dependency>
<!-- slf4j to log4j2 -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.11.1</version>
</dependency>
"配置"文件两个log4j2.xml
和log4j.properties
,可以参考上篇中对应内容,直接拿过来用就行。
(注:如需要,可以设置输出 log 文件的路径相同,这样就会写到同一个文件中了。)
兼容性 - 解决2
如果再深入挖掘一点,我不想要两个 log4j 的配置文件,就想要一个 log4j.properties
,可以实现吗?
当然!不过我们需要改变一下策略:
- Log4j 使用
log4j.properties
,输出一份到对应文件 - Log4j2 桥接到 Slf4j ,输出一份到对应文件
- Slf4j 搭配 Log4j ,输出一份到对应文件
其它都不用动,配置文件只留一个 log4j.properties
即可。
依赖修改如下:
<!-- log4j -->
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>1.2.17</version>
</dependency>
<!-- log4j2 -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.11.1</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.11.1</version>
</dependency>
<!-- slf4j -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.25</version>
</dependency>
<!-- slf4j to log4j -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.7.25</version>
</dependency>
<!-- log4j2 to slf4j -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-to-slf4j</artifactId>
<version>2.11.1</version>
</dependency>
这里起到实际作用的,是slf4j-log4j12
,以及log4j-to-slf4j
这两个 jar 。
(见参考1)
实战 - 日志兼容性问题解决
问题
工作中遇到这样一个问题,我正在重构某个项目,完了之后测试,发现启动不起来了,报错如下
console log
ERROR StatusLogger Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...
log file
Error creating bean with name 'Signalman': Cannot resolve reference to bean 'gemfireCache' while setting bean property 'cache';
nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'gemfireCache': Invocation of init method failed;
nested exception is java.lang.ExceptionInInitializerError
分析1
初步判断是 Log4j2 兼容性问题。
于是我使用 mvn depdendency:tree
,重点查看 log 相关的依赖是否有兼容性问题。
但是看了半天,没看出啥问题。
分析2
目前获知的信息太少,很难进一步分析。(这里错误日志打得有点问题,没有 stack trace。)
于是我费了一番周折,把打 log 的代码改了改,使其能打出 stack trace 如下:
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'gemfirePool': Invocation of init method failed; nested exception is java.lang.ExceptionInInitializerError
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1704)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:583)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:502)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:312)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:228)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:310)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:740)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:868)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:549)
at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:144)
at org.springframework.context.support.ClassPathXmlApplicationContext.<init>(ClassPathXmlApplicationContext.java:95)
at com.nomura.fixp.common.Environment.initialize(Environment.java:190)
at com.nomura.fixp.common.Environment.initialize(Environment.java:102)
at com.nomura.unity.udw.housekeeping.HouseKeepingMain.main(HouseKeepingMain.java:58)
Caused by: java.lang.ExceptionInInitializerError
at org.apache.geode.internal.cache.PoolManagerImpl.<clinit>(PoolManagerImpl.java:53)
at org.apache.geode.cache.client.PoolManager.find(PoolManager.java:60)
at org.springframework.data.gemfire.client.PoolFactoryBean.afterPropertiesSet(PoolFactoryBean.java:128)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1763)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1700)
... 14 more
Caused by: java.lang.ClassCastException: org.apache.logging.log4j.simple.SimpleLogger cannot be cast to org.apache.logging.log4j.core.Logger
at org.apache.geode.internal.logging.LogService.init(LogService.java:81)
at org.apache.geode.internal.logging.LogService.<clinit>(LogService.java:72)
... 19 more
有了 stack trace,就能进一步分析下去了,报的错其实是 ClassCastException
,进入第三方包 geode
,看看 org.apache.geode.internal.logging.LogService.init
是怎么写的:
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
private static void init() {
LoggerContext context = ((org.apache.logging.log4j.core.Logger) LogManager
.getLogger(BASE_LOGGER_NAME, GemFireParameterizedMessageFactory.INSTANCE)).getContext();
context.removePropertyChangeListener(propertyChangeListener);
context.addPropertyChangeListener(propertyChangeListener);
context.reconfigure(); // propertyChangeListener invokes configureFastLoggerDelegating
configureLoggers(false, false);
}
这里,它使用 LogManager.getLogger
取得一个 Logger ,然后尝试 cast 成 org.apache.logging.log4j.core.Logger
。但是,Logger 没有取到,返回的是默认的 SimpleLogger
,cast 的时候就报错了。
进一步深入,看看 getLogger
是咋实现的。然后,我竟然惊奇地发现,我们的依赖中,有两个实现!
IMPL 1
-> dremio-jdbc-driver:4.1.2xxxmapr
org.apache.logging
IMPL 2
-> log4j-api:2.7
org.apache.logging
讲道理,"IMPL 2" 才是 "合法的" logging framework 的实现。"IMPL 1" 应该是这个第三方库 dremio jdbc driver
自己做的一个 hack ,硬生生地 hardcode 一个 logging framework ...
经过一番比较,两者的实现非常类似,但是略微有些不同。(估计是不同版本间的差距)这也解释了为什么,一开始看 dependency tree 的时候看不出问题。因为人家并不依赖于第三方 jar 包,而是直接把第三方"融合"进自己的代码里 😃
解决
短期方案:改动自己的 pom.xml
,把 log4j 的顺序放在 dremio 前面,这样,gemfier 初始化时 getLogger
按顺序优先拿到 log4j 的实现,就能正常工作了。
长期方案:提 ticket 给 dremio 团队,报告这个 bug ,让它把 logging 这一块修复一下。
参考
- 参考1:Log4j Runtime Dependencies https://logging.apache.org/log4j/2.x/runtime-dependencies.html#log4j-slf4j-impl