今天公司同事上线时发现,有的机器打印了日志,而有的机器则一条日志也没有打。以往都是没有问题的。
因此猜测是这次开发间接引入新的日志jar包,日志冲突导致未打印。
排查代码发现,系统使用的是SLF4J框架打印log4j2的日志。查看系统中引入的jar包发现果然有多个SLF4J的桥接包。于是排掉冲突jar包,然后上线时所有机器都正常打印日志
先上一张关系图:SLF4J框架、各种具体日志实现以及相应桥接包的关系图
一、起因
由于线上系统要接入很多中间件,因此系统中会有各种各样的日志打印形式(例如:log4j2、JCL、logback等等)。
为了能整合所有日志并进行统一打印,最常用的就是SLF4J框架。
SLF4J框架作为门面框架,并没有日志的具体实现。而是通过和其他具体日志实现进行关联转换,并在系统中配置一种日志实现进行打印。
于是就很容易造成jar包引入冲突,导致有多个日志实现。当SLF4J框架选择的日志实现和我们配置的不一致时,就会打印不出日志。
SLF4J框架发现有多个日志实现时,是会打印提示信息的。但由于是标准错误输出,会在控制台(Tomcat的catalina.out)中打印【当业务日志文件中没有日志打印时,可以查看catalina.out是否有提示】
二、为什么只有部分机器打印
因为每个SLF4J的桥接包都有org.slf4j.impl.StaticLoggerBinder
SLF4J则会随机选择一个使用。当选择的跟系统配置的一样时就可以打印日志,否则就打印不出。
三、快速感知到多种SLF4J桥接包
如上图所示findPossibleStaticLoggerBinderPathSet方法,当有多个日志桥接包时会返回一个Set集合且提示一条信息。
由于这个信息提示并不强烈,不易感知。我们可以根据这一点,使用反射来获取到系统中实际的桥接包数量,并做自定义的提示。
1、实现spring的BeanFactoryPostProcessor,并将其交由spring管理。保证系统启动后,自动进行日志冲突校验
2、使用反射获取LoggerFactory的实例以及findPossibleStaticLoggerBinderPathSet方法的返回结果
3、根据桥接包数量判断是否异常,进行自定义报警
4、根据报警信息,进行排包
<bean class="LogJarConflictCheck" />
/**
* 日志jar包冲突校验
*/
public class LogJarConflictCheck implements BeanFactoryPostProcessor {
@Override
public void postProcessBeanFactory(ConfigurableListableBeanFactory configurableListableBeanFactory) throws BeansException {
try {
Class<LoggerFactory> loggerFactoryClazz = LoggerFactory.class;
Constructor<LoggerFactory> constructor = loggerFactoryClazz.getDeclaredConstructor();
constructor.setAccessible(true);
LoggerFactory instance = constructor.newInstance();
Method method = loggerFactoryClazz.getDeclaredMethod("findPossibleStaticLoggerBinderPathSet");
// 强制进入
method.setAccessible(true);
Set<URL> staticLoggerBinderPathSet = (Set<URL>)method.invoke(instance);
if (CollectionUtils.isEmpty(staticLoggerBinderPathSet)) {
handleLogJarConflict(staticLoggerBinderPathSet, "Class path is Empty.添加对应日志jar包");
}
if (staticLoggerBinderPathSet.size() == 1) {
return;
}
handleLogJarConflict(staticLoggerBinderPathSet, "Class path contains multiple SLF4J bindings. 注意排包");
} catch (Throwable t) {
t.getStackTrace();
}
}
/**
* 日志jar包冲突报警
* @param staticLoggerBinderPathSet jar包路径
* @param tip 提示语
*/
private void handleLogJarConflict (Set<URL> staticLoggerBinderPathSet, String tip) {
String ip = getLocalHostIp();
StringBuilder detail = new StringBuilder();
detail.append("ip为").append(ip).append("; 提示语为").append(tip);
if (CollectionUtils.isNotEmpty(staticLoggerBinderPathSet)) {
String path = JsonUtils.toJson(staticLoggerBinderPathSet);
detail.append("; 重复的包路径分别为 ").append(path);
}
String logDetail = detail.toString();
//TODO 使用自定义报警通知logDetail信息
}
private String getLocalHostIp() {
String ip;
try {
InetAddress addr = InetAddress.getLocalHost();
ip = addr.getHostAddress();
} catch (Exception var2) {
ip = "";
}
return ip;
}
}
四、一次配置,终生可靠
上面的方式也只是帮助我们快速感知到日志jar包冲突,仍需手动排包。
是否存在一种解决方法,能帮忙我们彻底解决这种问题呢?
答案是有
即将我们需要引入的jar包和需要排掉的jar包声明到maven的最上层,将需要排掉的包声明为provided即可
这种方案是利用maven的扫包策略:
1、依赖最短路径优先原则;
2、依赖路径相同时,申明顺序优先原则
当我们将所有jar包声明为直接依赖后,会优先被使用。
而我们需要排掉的包只要声明为provided,就不会打入包中。
从而实现需要的包以我们声明的为准,需要排掉的包也不会被间接依赖影响
<properties>
<slf4j.version>1.7.7</slf4j.version>
<logback.version>1.2.3</logback.version>
<log4j.version>1.2.17</log4j.version>
<log4j2.version>2.3</log4j2.version>
<jcl.version>1.2</jcl.version>
</properties>
<dependencies>
<!--系统使用log4j2作为系统日志实现 slf4J作为门面 -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>${slf4j.version}</version>
</dependency>
<!--使用log4j2作为实际的日志实现-->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>${log4j2.version}</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>${log4j2.version}</version>
</dependency>
<!--将log4j、logback、JCL的jar包设置为provided,不打入包中-->
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>${log4j.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>${logback.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
<version>${jcl.version}</version>
<scope>provided</scope>
</dependency>
<!--为防止循环转换,排掉log4j2转slf4j的桥接包-->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-to-slf4j</artifactId>
<version>${log4j2.version}</version>
<scope>provided</scope>
</dependency>
<!--声明log4j、JCL、JUL转slf4j的桥接包,代码中对应日志可以转成SLF4J-->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>log4j-over-slf4j</artifactId>
<version>${slf4j.version}</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jcl-over-slf4j</artifactId>
<version>${slf4j.version}</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jul-to-slf4j</artifactId>
<version>${slf4j.version}</version>
</dependency>
<!--声明slf4j转SLF4J的桥接包-->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>${log4j2.version}</version>
</dependency>
<!--排掉slf4j转log4j、JCL、JUL转slf4j的桥接包的桥接包,防止日志实现jar包冲突-->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>${slf4j.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-jdk14</artifactId>
<version>${slf4j.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-jcl</artifactId>
<version>${slf4j.version}</version>
<scope>provided</scope>
</dependency>
</dependencies>
总结
第三步的方案:启动时感知系统是否存在日志jar包冲突,冲突后手动排包
第四步的方案:一次声明所需的所有日志jar包配置,无需在担心冲突问题
------The End------
如果这个办法对您有用,或者您希望持续关注,也可以扫描下方二维码或者在微信公众号中搜索【码路无涯】