作者:Sharehub
Java 有很多的日志框架可以选择,当同一个项目中出现多种日志框架时就很容易出现日志框架冲突的问题,导致日志打印不出来。本文将以一次典型的日志冲突排查问题为例,提供排查步骤和思路,最后分析日志框架冲突的原因。
一般行文思路都是先讲 Why,再讲 How,这里我颠倒了,因为一般遇到问题的时候我们对问题背后的根本原因是一无所知的,如果我们已经知道问题的原因,那么问题也就迎刃而解了。
因此我希望先复现我当时在对日志框架了解不多的情况下排查问题的思路和步骤,如何在面对未知问题找到破题思路是非常重要的技能。
在 A 工程中,日志框架配置选用了 Log4j2,master 分支上日志打印正常,但开发分支增加了代码之后日志打印不出来。项目的依赖中包含了 Log4j2、Logback 等日志框架。
排查问题的时候首先必须要有明确的思路,即大胆假设,小心求证,不能像无头苍蝇一样乱试。从问题的现象看,直觉上可以得出几个假设:
接下来就是验证假设,首先多申请几台机器部署项目分支,发现问题仍然存在,可以排除第一个假设。其次找到另一个工程 B 跟 A 工程对比 Log4j2 的配置,也没有发现明细的差异,可以排除第二个假设。
在已有假设都验证失败的情况下,需要收集更多的信息作出判断,接下来就是要用对照实验收集信息。于是我分别断点了 A 和 B 两个工程,观察它们日志实体的类型是否一致。结果发现两者的日志实体类型不一样,A 的日志实现是 Logback,B 的日志实现是 Log4j2,很明显 A 打印不出日志是因为日志实体不对,但是两者都是用的同一个 LoggerFactory 创建 Logger 的。
从对照实验的结果来看,可以得出一个假设:依赖冲突导致了 A 运行时使用日志实体不是 Log4j2。
至此我们已经找到了问题的大致方向,接下来就是要排包。排包一般有两种思路:
暴力求解的方式太花费时间了,所以我用的第二种方式。
获取日志实体的方式如下:
privatestaticfinalLoggerLOGGER=LoggerFactory.getLogger(xxx.class);
LoggerFactory 的代码如下:
从代码上可以发现,getLog方法是来自父类LogFactory,当我去尝试获取LogFactory的实现时候,发现竟然有 3 个 jar 中都有同样包名的LogFactory实现。于是我断点了 A 和 B 工程的代码,用 IDEA 的运行代码功能执行以下命令获取LogFactory的加载信息。
结果发现 B 工程使用是spring-jcl,A 使用的是jcl-over-slf4j,然后排除掉 A 中jcl-over-slf4j,问题解决。
上面的排查过程中,关键的地方有两点:
问题至此就解决了,但是还有一个更深入的问题没有解决:为什么同时存在多个日志框架的时候就会出现冲突呢?在解决完问题之后,我深入研究了日志框架的历史和设计,发现原来这跟日志框架的实现机制有关系。
首先要从日志框架的发展历史开始说起。
至此我们已经有了三个的 Log 接口和四个 Log 实现,果然程序员真的是爱造轮子。出现这么多框架之后,有人开始搞各个框架之间的桥接,你兼容我,我兼容你,如下图所示。
因为很多 jar 使用的日志框架不同,所以经常会出现引入 jar 包之后导致日志类冲突,前面我们排查的那个问题就是因为引入了 jcl-over-slf4j 的桥接包。
前面我们提到日志框架分为日志接口和日志实现,只要我们代码中使用的是日志接口(JCL、SLF4J),我们可以随时替换日志的实现。
SLF4J 加载日志实现分为两个步骤:
SLF4J 要求日志实现 jar 包都要实现 StaticLoggerBinder 这个类,而且要放在指定目录:org/slf4j/impl/StaticLoggerBinder.class,SLF4J 的LoggerFactory会去扫描所有 jar 包中的这个地址,参考下面的代码。
虽然它扫描了多个日志实现,但实际上同名类 JVM 只能存在一个,它这里扫描的目的是为了打印日志告诉用户有多少个日志实现在依赖包中。下面的代码返回的是最终使用的日志实现。
你可能要问了,同时存在多个日志实现类的时候,到底是用的是哪个?答案很简单,因为 SLF4J 利用了静态类来加载日志工程,实际上就是让 JVM 决定使用哪个类:哪个被先加载到 JVM 中就用哪个。为了搞清楚这个问题的答案,我特地去看了URLClassPath加载类的实现,它就是按照 jar 加入到 URLClassPath的顺序遍历扫描,找到第一个符合条件的就返回。
相比 SLF4J 比较任性的加载方式(依赖 JVM 加载类的顺序),JCL 提供了更多的配置能力,可以指定使用哪一个日志工程类。
类似的,JCL 也分为两个步骤加载日志实现:
首先是获取 LogFactory:
找到 LogFactory 之后就根据 LogFactory 获取 Logger,这个根据不同的 LogFactory 实现有不同的方式。前面我遇到那个问题就是因为类冲突导致使用了 SLJ4J 的 LogFactory ,加载了错误的 Logger。
开发过程中总会遇到奇奇怪怪的问题,有无处下手的感觉时先稳住心态,按照大胆假设,小心求证的方式进行排查,实在没有思路往往是因为基础还不扎实。
像这次日志打印不出来的问题,如果了解日志框架的加载实现,很容易就能定位到问题;差一点的像我不了解日志框架的实现,但是我可以根据之前对类加载机制的了解也能解决问题;如果对类加载机制不了解,那基本上是无解了。
因此,要把问题当做学习机会,不光要解决问题,还要深挖背后的原理,做好总结,这样才能为解决更多的问题打下扎实基础。