一次日志框架排坑记录
一个Java项目中,由于引入的依赖可能使用各种不同的日志框架,并且各个模块的开发人员在没有硬性要求时会习惯性地使用自己熟悉的框架,这就导致项目中对各种日志框架的依赖各式各样,排查起来很麻烦。
例如,项目写日志的代码中,有直接使用Log4j的这种写法:
// 使用 log4j.log4j 1.2.17
import org.apache.log4j.Logger;
...
private Logger logger = Logger.getLogger(DBConnectionUtils.class);
logger.error("error");
...
也有直接使用 Log4j 2的写法:
// 使用 org.apache.logging.log4j.log4j-api 2.10.0
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
...
private Logger logger = LogManager.getLogger("loggerName");
logger.error("error");
...
还有使用 Slf4j 的写法:
// 使用 org.slf4j.slf4j-api 1.7.25
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
...
public Logger logger = LoggerFactory.getLogger("loggerName");
logger.error("error");
...
// 或使用 lombok 的Slf4j注解
import lombok.extern.slf4j.Slf4j;
// 利用注解产生log变量
@Slf4j
public class TestClass {
public void testMethod() {
log.error("error");
}
}
由于项目日志的配置使用的log4j.xml,对应 log4j2 ,因此 log4j1 的使用应该是无效的,所有显式使用log4j1的地方需要全部改掉。
Slf4j 是一个日志接口,能兼容多种日志实现,如 log4j / JCL(java commons logging) / logback / java.util.logging , 能带来很好的扩展性,建议使用。因此所有显式使用 log4j2 的代码也需要改成 slf4j 。
由于三种写法的代码文件都很多,必须写一个脚本来实现代码替换,预先将目标文件的路径存放于 tmp_list 中,然后在同目录下执行下列脚本:
#!/bin/sh
# Env: MacBookPro11,4; 版本 10.13.3(版号 17D47)
for DIR in `cat tmp_list`; do
echo $DIR
# 替换import org.apache.log4j.Logger;这行
find $DIR -type f -name *.java -exec sed -i '' '/import org.apache.log4j.Logger;/d' {} \;
# 替换*Logger logger =*这行
find $DIR -type f -name *.java -exec sed -i '' '/Logger logger =/d' {} \;
# 替换logger为log
find $DIR -type f -name *.java -exec sed -i '' 's/logger/log/g' {} \;
# 在public abstract class上一行添加@Slf4j
find $DIR -type f -name *.java -exec sed -i '' '/public abstract class/i\
@lombok.extern.slf4j.Slf4j\
' {} \;
# 在public class上一行添加@Slf4j
find $DIR -type f -name *.java -exec sed -i '' '/public class/i\
@lombok.extern.slf4j.Slf4j\
' {} \;
done;
执行结束后,代码编译通过,说明没有明显的替换错误。但是工程启动后,发现有报错,TDDL 客户端抛出了以下异常(已经隐去不相干的若干行):
JM.Log:ERROR Failed to get Slf4jLogger
java.lang.IllegalArgumentException: delegate must be logback impl or slf4j-log4j impl
at com.taobao.middleware.logger.slf4j.Slf4jLogger.<init>(Slf4jLogger.java:50)
at com.taobao.middleware.logger.slf4j.Slf4jLoggerFactory.getLogger(Slf4jLoggerFactory.java:17)
at com.taobao.middleware.logger.LoggerFactory.getLogger(LoggerFactory.java:60)
at com.taobao.middleware.logger.LoggerFactory.getLogger(LoggerFactory.java:69)
at com.taobao.diamond.client.impl.LogUtils.logger(LogUtils.java:36)
at com.taobao.diamond.client.impl.DiamondEnv.<clinit>(DiamondEnv.java:696)
at com.taobao.diamond.client.impl.DiamondEnvRepo.<clinit>(DiamondEnvRepo.java:93)
at com.taobao.tddl.config.diamond.DiamondConfigDataHandler.doInit(DiamondConfigDataHandler.java:50)
at com.taobao.tddl.common.model.lifecycle.AbstractLifecycle.init(AbstractLifecycle.java:32)
at com.taobao.tddl.config.impl.PreheatDataHandler.doInit(PreheatDataHandler.java:37)
at com.taobao.tddl.common.model.lifecycle.AbstractLifecycle.init(AbstractLifecycle.java:32)
at com.taobao.tddl.config.impl.UnitConfigDataHandlerFactory.getConfigDataHandler(UnitConfigDataHandlerFactory.java:66)
at com.taobao.tddl.config.impl.UnitConfigDataHandlerFactory.getConfigDataHandler(UnitConfigDataHandlerFactory.java:52)
at com.taobao.tddl.matrix.jdbc.TDataSource.loadConnectionProperties(TDataSource.java:197)
at com.taobao.tddl.matrix.jdbc.TDataSource.doInit(TDataSource.java:127)
at com.taobao.tddl.common.model.lifecycle.AbstractLifecycle.init(AbstractLifecycle.java:32)
...
...
at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:829)
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 sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
at sun.rmi.transport.Transport$1.run(Transport.java:200)
at sun.rmi.transport.Transport$1.run(Transport.java:197)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:264)
at com.taobao.middleware.logger.slf4j.Slf4jLogger.<init>(Slf4jLogger.java:46)
... 115 more
通过Debug,发现问题出在这里:
从上图可以看到,tddl 底层的中间件代码中,日志代理类只可以是 ch.qos.logback.classic.Logger 和 org.slf4j.impl.Log4jLoggerAdapter, 而我们的代理类却默认初始化成了 org.apache.logging.slf4j.Log4jLogger, 为什么会出现这个情况呢?猜测 log4j-slf4j-impl 在初始化的时候是优先于 slf4j-log4j12 的 ,把 org.apache.logging.slf4j.Log4jLogger 所在的如下依赖从 pom 中去掉看看。
结果初始化时恢复到了 org.slf4j.impl.Log4jLoggerAdapter 了,问题得到解决。此时,比较下 log4j-slf4j-impl 和 slf4j-log4j12 的区别,我们可以得出以下结论:
log4j-slf4j-impl 是 slf4j 和 logj4 2 的 Binding,而 slf4j-log4j12 是 slf4j 和 log4j 1.2 的 Binding,com.taobao.middleware 这项服务底层硬编码只支持 slf4j-log4j12 和 logback ,并不支持 log4j2,尽管 log4j2 已经用于很多大型项目了。