简介:在研究Dubbo3的时候,为了图简单,就直接使用了 jul 作为dubbo 运行时的日志框架了,但是在研究时,发现了一些日志的使用的隐藏问题,在此记录一下
问题起因在官方文档中对日志有以下描述,这里我截图放在下面
所以我理解应该只需要在 配置文件中,配置一下 logger = jdk,然后将jdk的日志配置文件复制一份放在 resource 目录下就可以了,于是我在 dubbo.properties文件中加入配置
dubbo.application.logger=jdk
但是发现刚开始启动的有一部分日志无法打印出来,同样使用<dubbo:application logger="log4j" />
也无法打印出来日志,入下图
但是使用java -Ddubbo.application.logger=log4j
,这种日志就可以打印出来,如下图
此时我的maven依赖如下
<dependencies>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo</artifactId>
<version>3.0.2</version>
</dependency>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo-dependencies-zookeeper</artifactId>
<version>3.0.3</version>
<type>pom</type>
</dependency>
<dependency>
<groupId>junit</groupId>
<artifactId>junit</artifactId>
<version>4.13.2</version>
<scope>test</scope>
</dependency>
</dependencies>
检查源码
dubbo框架自己又重写了一个 一个日志适配框架,统一入口是org.apache.dubbo.common.logger.LoggerFactory
里面有一段很关键的源码
private static volatile LoggerAdapter LOGGER_ADAPTER;
static {
String logger = System.getProperty("dubbo.application.logger", "");
switch (logger) {
case "slf4j":
setLoggerAdapter(new Slf4jLoggerAdapter());
break;
case "jcl":
setLoggerAdapter(new JclLoggerAdapter());
break;
case "log4j":
setLoggerAdapter(new Log4jLoggerAdapter());
break;
case "jdk":
setLoggerAdapter(new JdkLoggerAdapter());
break;
case "log4j2":
setLoggerAdapter(new Log4j2LoggerAdapter());
break;
default:
List<Class<? extends LoggerAdapter>> candidates = Arrays.asList(
Log4jLoggerAdapter.class,
Slf4jLoggerAdapter.class,
Log4j2LoggerAdapter.class,
JclLoggerAdapter.class,
JdkLoggerAdapter.class
);
for (Class<? extends LoggerAdapter> clazz : candidates) {
try {
setLoggerAdapter(clazz.newInstance());
break;
} catch (Throwable ignored) {
}
}
}
}
public static void setLoggerAdapter(LoggerAdapter loggerAdapter) {
if (loggerAdapter != null) {
if (loggerAdapter == LOGGER_ADAPTER) {
return;
}
loggerAdapter.getLogger(LoggerFactory.class.getName());
LoggerFactory.LOGGER_ADAPTER = loggerAdapter;
for (Map.Entry<String, FailsafeLogger> entry : LOGGERS.entrySet()) {
entry.getValue().setLogger(LOGGER_ADAPTER.getLogger(entry.getKey()));
}
}
}
这段代码的逻辑很简单,就是dubbo 为常用的日志框架,都做了一个适配器,然后根据 vm参数,来判断使用哪一个日志框架的适配器,所以从Main启动开始,如果没有指定 vm参数 则通过逐个 实例化的方式,那个日志框架的依赖存在,就使用那个,如果多个日志框架都存在,则默认优先级从高到低为:Log4j > Slf4j > Log4j2 > Jcl >jdk
而zookeeper的依赖中,有 slf4j和log4j 的依赖,所以,在一开始,程序刚刚启动时
如果 指定了 vm参数,使用的就是 jdk的适配器,此时所有的日志都能打印出来
如果没有指定vm参数,使用的是配置文件的方式,由于有log4j的依赖,所以使用的是 log4j的适配器,但是我又没有配置 log4j的日志配置文件,导致刚开始日志没有打出来
单随着程序的启动,读取了dubbo.properties的配置文件,以及加载各种dubbo配置,这里就不展开说了,一直到 ApplicationConfig
这个配置类进行初始化,会读取配置中的 logger = jdk,然后将 org.apache.dubbo.common.logger.LoggerFactory
中的 日志适配器更改为 jdk的日志适配器,后面的日志就全部打印出来了,代码如下
public void setLogger(String logger) {
this.logger = logger;
LoggerFactory.setLoggerAdapter(logger);
}
思考
实际我们开发和运维过程中,使用 vm参数是非常不方便的,很多人更喜欢使用配置文件,虽然日志框架一但选定,一般不会进行更改,但是如果真的还是想使用配置文件的方式该怎么办呢?
前面我们看到,如果多个日志框架都存在,则默认优先级从高到低为:Log4j > Slf4j > Log4j2 > Jcl >jdk,那我们把所有高于jdk的日志框架都排除调不就默认是jdk的日志框架了,但这样是不行的,因为 dubbo中依赖的spring框架,spring中使用jcl作为日志框架,并且zookeeper中使用slf4j作为日志门面,这些事直接依赖,一点排除,应用就起不起来了,如下图
<dependencies>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo</artifactId>
<version>3.0.2</version>
<exclusions>
<exclusion>
<artifactId>spring-jcl</artifactId>
<groupId>org.springframework</groupId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo-dependencies-zookeeper</artifactId>
<version>3.0.3</version>
<type>pom</type>
<!-- 移除所有的日志依赖 -->
<exclusions>
<exclusion>
<artifactId>log4j</artifactId>
<groupId>log4j</groupId>
</exclusion>
<exclusion>
<artifactId>slf4j-log4j12</artifactId>
<groupId>org.slf4j</groupId>
</exclusion>
<exclusion>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>junit</groupId>
<artifactId>junit</artifactId>
<version>4.13.2</version>
<scope>test</scope>
</dependency>
</dependencies>
启动报错,可以看到,虽然使用jdk日志框架,但是应用起不来,无论缺少了 jcl还是slf4j,应用都无法起来
那其实还有一种更好的办法,就是使用 slf4j 的日志桥接,因为slf4j是日志门面,只需要加入 slf4j -> jul的桥接依赖即可,这样虽然应用一开始启动时使用的是slf4j的适配器,但是最终日志是转发到了jdk日志框架,随着应用启动各项配置加载完成,适配器最后变成了jdk适配器,这样就不会出现一开始的日志丢失,也使用了配置文件的方式
maven如下
<dependencies>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo</artifactId>
<version>3.0.2</version>
</dependency>
<dependency>
<groupId>org.apache.dubbo</groupId>
<artifactId>dubbo-dependencies-zookeeper</artifactId>
<version>3.0.3</version>
<type>pom</type>
<exclusions>
<exclusion>
<artifactId>log4j</artifactId>
<groupId>log4j</groupId>
</exclusion>
<exclusion>
<artifactId>slf4j-log4j12</artifactId>
<groupId>org.slf4j</groupId>
</exclusion>
<!-- juc桥接依赖中有slf4j-api依赖,此处也可以排掉,不排除也没事,maven依赖管理也会帮我们排除 -->
<exclusion>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-jdk14</artifactId>
<version>1.7.25</version>
</dependency>
<dependency>
<groupId>junit</groupId>
<artifactId>junit</artifactId>
<version>4.13.2</version>
<scope>test</scope>
</dependency>
</dependencies>
此时就大功告成了,当时这只是我平时的学习,真正开发时,没人会用 jdk 日志框架,也就不会出现这种问题
补充最后看一下dubbo的日志适配,也就用我上面的 使用 slf4j-jdk14 的例子讲解,我这里debug截图了一下
当排除了其他日志框架,只剩 slf4j的依赖时,dubbo的日志适配就是 Slf4jLoggerAdapter
,在需要创建 logger对象时
就用Slf4jLoggerAdapter
创建一个 org.apache.dubbo.common.logger.slf4j.Slf4jLogger
对象,
org.apache.dubbo.common.logger.slf4j.Slf4jLogger
对象中包含了一个org.slf4j.Logger
对象,这个就是slf的门面
由于此时我们,引入的是 slf4j-jdk14,
所以这个org.slf4j.Logger
的实现是org.slf4j.impl.JDK14LoggerAdapter
而org.slf4j.impl.JDK14LoggerAdapter
中又包含了 真正的jdk的日志对象java.util.logging.Logger
在org.apache.dubbo.common.logger.slf4j.Slf4jLogger
创建完成后,又将其放入org.apache.dubbo.common.logger.support.FailsafeLogger
,用FailsafeLogger作为整个dubbo日志的统一门面
这其中是适配器模式和门面模式的体现