1. 问题回顾
问题背景是在进行中台应用中间件迁移过程中,发现存在项目启动失败或者项目正常启动(jsf正常挂载并正常运行,mq正常发送和消费)但是无任何日志打印现象。更奇怪的是不打印日志竟然是偶发的,在测试环境中多次部署都未出现项目启动但无日志打印情况,而且玄学的是生产环境两台机器,其中一台正常日志打印,另一台无任何日志打印(应用运行正常)。
通过多次重启无日志打印机器仍未恢复日志打印,最终通过排查发现问题在于项目中引入的多个日志jar包冲突,进而导致无日志打印现象。
图1 场景1项目启动失败和场景2项目目正常启动但是无日志打印
图2 运行项目所包含的日志jar包
2. 日志框架
日志框架通常分为两大类:
•日志门面(Logging Facade):如SLF4J(Simple Logging Facade for Java)和JCL(Apache Commons Logging),它们提供了一层抽象接口,使得开发者可以编写与具体日志实现无关的代码。这样在不修改代码的情况下,可以灵活地切换底层的日志实现框架。
•日志实现(Logging Implementation):如Logback、Log4j、java.util.logging (JUL)等,它们是具体的日志库,负责实际的日志生成、处理和存储工作。这些实现直接响应门面层的请求,执行日志操作。
图3 日志门面和日志实现
日志门面使用到了一种设计模式:门面模式,接下来简单介绍下门面模式。下面是门面模式的一个典型调用过程,其核心为外部与一个子系统的通信必须通过一个统一的外观对象进行,使得子系统更易于使用。 下图中客户端不需要直接调用几个子系统,只需要与统一的门面进行通信即可。
图4 门面模式的一个典型调用过程
门面模式的核心为Facade即门面对象,核心为几个点:
•知道所有子角色的功能和责任。
•将客户端发来的请求委派到子系统中,没有实际业务逻辑。
•不参与子系统内业务逻辑的实现。
举个栗子
当你通过电话给商店下达订单时, 接线员就是该商店的所有服务和部门的外观。 接线员为你提供了一个同购物系统、 支付网关和各种送货服务进行互动的简单语音接口。
注: 具体想要了解门面模式的可以参看这篇文章。
2.1 为什么要引入日志门面?
回答这个问题之前,我们先看看如果需要用上面几个日志框架来打印日志,一般怎么做,具体代码如下:
// 使用log4j,需要log4j.jar
import org.apache.log4j.Logger;
Logger logger_log4j = Logger.getLogger(Test.class);
logger_log4j.info("Hello World!");
// 使用log4j2,需要log4j-api.jar、log4j-core.jar
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
Logger logger_log4j2 = LogManager.getLogger(Test.class);
logger_log4j2.info("Hello World!");
// logback,需要logback-classic.jar、logback-core.jar
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
Logger logger_logback = new LoggerContext().getLogger(Test.class);
logger_logback.info("Hello World!");
从上面不难看出,使用不同的日志框架需要要引入不同的jar包,使用不同的代码获取Logger。如果项目升级需要更换不同的框架,那么就需要修改所有的地方来获取新的Logger,这将会产生巨大的工作量。
基于此,我们需要一种接口来将不同的日志框架的使用统一起来,这也是为什么要使用SLF4J的原因。
日志门面——SLF4J
即简单日志门面(Simple Logging Facade for Java),不是具体的日志解决方案,它只服务于各种各样的日志系统。按照官方的说法,SLF4J是一个用于日志系统的简单Facade,允许最终用户在部署其应用时使用其所希望的日志系统。
另一个常用的日志门面——JCL
常见的日志门面还有一个叫JCL(Jakarta Common logging),这个是在2001年左右旨在解决日志实现多样性的问题,允许开发者编写与具体日志实现无关的代码,并作为第一个广泛使用的日志门面被提出了。其中SLF4J日志门面是在2006年,由Ceki Gülcü,同时也是Log4j的创始人,推出了SLF4J,这是一个更为先进、设计更优的日志门面,旨在克服JCL存在的问题,如类加载冲突和运行时绑定的不确定性。
2.2 SLF4J和JCL的主要区别?
- 动态与静态绑定
•JCL:采用动态绑定机制,意味着它在运行时通过类加载器查找并决定使用哪个日志实现(如Log4j、JUL等)。这种方式可能导致类加载顺序问题,尤其是在类路径复杂的应用中,可能会引起不确定性和潜在的类加载冲突。
•SLF4J:提倡静态绑定,即在编译时就确定日志实现。SLF4J要求在类路径中明确包含一个到具体日志实现的桥接器(如slf4j-log4j12.jar),这样在编译时就能确切知道日志将如何被处理。这减少了运行时的不确定性,提高了性能,并且在日志实现未正确配置时能给出更明确的错误提示。
- 错误处理与诊断
•JCL:如果日志实现没有正确配置,可能会导致难以诊断的错误,比如NoClassDefFoundError或ClassNotFoundException,因为JCL在运行时才会发现日志实现不可用。
•SLF4J:在初始化时,如果发现不兼容的或缺失的日志实现,SLF4J会立即抛出一个明确的警告或错误信息,帮助开发者快速定位问题。
- 性能
•SLF4J:通常被认为比JCL有更高的性能,尤其是当使用静态绑定时,因为减少了解析和查找日志实现的开销。
- API设计
•SLF4J:提供了更简洁、更易用的API,支持更灵活的日志级别控制和参数化日志消息,有助于减少字符串拼接的开销。
- 社区与支持、更新与活跃度
•SLF4J:随着时间的推移,SLF4J因其设计优势获得了更广泛的社区支持和采纳,许多现代的Java库和框架直接支持或推荐使用SLF4J。
•SLF4J:相比JCL,SLF4J持续得到维护和更新,提供了对新特性和日志实现更好的支持。
综上所述,SLF4J在设计上克服了JCL的一些缺陷,提供了更稳定、高效和易于使用的日志接口,因此在新项目中更受推崇。而JCL尽管仍在一些遗留系统中使用,但已逐渐被SLF4J取代。
2.3 常用的日志实现
一些趣闻
使用过Log4J和LogBack的同学肯定能发现,这两个框架的设计理念极为相似,使用方法也如出一辙。其实这个两个框架的作者都是一个人,Ceki Gülcü,土耳其软件工程师。 Log4J 最初是基于Java开发的日志框架,发展一段时间后,作者Ceki Gülcü将Log4j捐献给了Apache软件基金会,使之成为了Apache日志服务的一个子项目。 又由于Log4J出色的表现,后续又被孵化出了支持C, C++, C#, Perl, Python, Ruby等语言的子框架。 然而,伟大的程序员好像都比较有个性。Ceki Gülcü由于不满Apache对Log4J的管理,决定不再参加Log4J的开发维护。“出走”后的Ceki Gülcü另起炉灶,开发出了LogBack这个框架(SLF4J是和LogBack一起开发出来的)。LogBack改进了很多Log4J的缺点,在性能上有了很大的提升,同时使用方式几乎和Log4J一样,许多用户开始慢慢开始使用LogBack。 由于受到LogBack的冲击,Log4J开始式微。终于,2015年9月,Apache软件基金业宣布,Log4j不再维护,建议所有相关项目升级到Log4j2。Log4J2是Apache开发的一个新的日志框架,改进了很多Log4J的缺点,同时也借鉴了LogBack,号称在性能上也是完胜LogBack。性能这块后续我会仔细分析。
根据这些日志实现的出现顺序及特点整理出了一条时间线如下:
1999年: Log4j 1.x:由Ceki Gülcü(土耳其裔美国软件工程师)创建,成为Java社区广泛采用的第一个流行日志框架。它的出现使得开发者能够更方便地控制日志记录,包括日志级别、输出格式和目的地。
2001年: JUL (Java Util Logging) :随着Java 1.4的发布,Oracle(当时是Sun Microsystems)引入了JUL作为标准的日志库。虽然它是一个内置的解决方案,但由于API相对复杂,开发者普遍认为它不如Log4j好用。
2003年: JCL (Apache Commons Logging) :Apache软件基金会推出JCL,作为日志门面,旨在提供一个统一的API,使得开发者可以编写与具体日志实现无关的代码。然而,JCL在运行时动态加载日志实现的方式导致了类加载问题和性能问题。
2006年: SLF4J (Simple Logging Facade for Java) :Ceki Gülcü,也是Log4j的创建者,推出了SLF4J,作为对JCL的改进。SLF4J强调静态绑定,提高了性能和稳定性,并且支持更多的日志实现,如Logback、Log4j 1.x等。
2007年: Logback:Ceki Gülcü同时推出了Logback,作为Log4j的替代,设计为SLF4J的首选实现。Logback提供了更高效、更灵活的日志记录功能,包括异步日志记录和丰富的配置选项。
2010年: Log4j 2.x:Apache Log4j项目在2010年代进行了重大升级,推出了Log4j 2,它修复了Log4j 1.x的一些问题,提供了更好的性能和更多特性,如异步日志记录和更强大的配置能力。
2010年至今: 微服务和云原生日志:随着微服务和云原生应用的兴起,日志收集和分析的需求变得更加复杂。工具如Loggly、Logstash、Fluentd、Elasticsearch、Kibana等开始流行,它们与各种日志实现配合,提供了日志的集中处理、搜索、分析和可视化。 现代轻量级日志框架:
TinyLog:针对简单应用和资源受限环境,轻量级的日志框架如TinyLog应运而生,提供简单易用的API,注重效率和小巧。
注: 对TinyLog感兴趣可参考这篇文章。
图5 日志演变路线
3. 日志门面和日志实现结合
3.1 日志门面如何和日志实现结合使用呢?
以比较常用的SLF4J为例,并结合现有比较常用的日志实现可归纳出以下几种组合依赖结构(如图6),即SLF4J绑定到具体日志实现时需要引入的jar包依赖。图6最下方给出的不同颜色的含义,分别是抽象接口、原生支持SLF4J的实现、适配层、非原生支持SLF4J的实现。
1.抽象接口层都是slf4j-api,很好理解,因为slf4j主要就是做日志门面。
2.原生支持SLF4J的实现:有logback、slf4j-simple.jar、slf4j-nop.jar。
3.非原生支持SLF4J的实现,有log4j和jul,因为这两个在SLF4J之前就出现了,后面SLF4j出现后,大家觉得这个日志门面很优秀,所以出现了适配SLF4J和log4j、jul的桥接包,也就是下图中的slf4j-reload4j.jar和slf4j-jdk14.jar
4.log4j2是最后出现的,可以说吸取了前面一些日志框架的优点,自成一体,所以未在下面的图中出现。当然SLF4J和log4j2也可以搭配,使用log4j-slf4j-impl的桥接包。
注:logback、slf4j-simple.jar、slf4j-nop.jar之所以能天然支持SLF4J的接口是有原因的,slf4j-simple.jar、slf4j-nop.jar都是slf4j自带的实现框架,本身就是按slf4j-api的接口开发的。logback之所以也天然适配SLF4J,有两个原因,一是出现的先后原因,log4j ->JUL->JCL-> SLF4J -> logback -> log4j2,logback在SLF4J后面出现,第二个是因为这两个都是同一个作者写的。
图6 SLF4J与日志实现结构图
总结来说主要的日志门面和日志实现的依赖搭配如下:
•slf4j + logback: slf4j-api.jar + logback-classic.jar + logback-core.jar
•slf4j + log4j 1. x : slf4j-api.jar + slf4j-log412.jar + log4j.jar
•slf4j + jul: slf4j-api.jar + slf4j-jdk14.jar
•slf4j无日志实现:slf4j-api.jar + slf4j-nop.jar (日志不会被记录:适合调试和测试环境,避免不必要的输出)
注意到这里没有log4j2依赖jar的关系,和log4j2配合需要导入log4j2的log4j-api.jar、log4j-core.jar和桥接包log4j-slf4j-impl.jar。
•slf4j + log4j 2.x :slf4j-api.jar + log4j-api.jar + log4j-core.jar + log4j-slf4j-impl.jar
•log4j 2.x : log4j-core + log4j-api (log4j 2.x 可单独使用)
3.2 什么是桥接包?
聊起桥接包,需要回顾下之前提到的SLF4J。SLF4J通过定义一套API,使得应用程序可以在不依赖具体日志实现的情况下进行日志记录。为了实现这一目标,SLF4J引入了StaticLoggerBinder这个关键组件。
StaticLoggerBinder是SLF4J API与底层日志实现之间的一个接口,它是一个单例类,负责在运行时返回日志实现的LoggerFactory实例。这个类的存在使得SLF4J能够在不直接引用具体日志库的情况下,依然能够找到并使用正确的日志实现。
桥接包(Bridge Package) 的作用是解决已有代码依赖特定日志框架(如Log4j 1.x)与SLF4J之间的兼容性问题。例如,slf4j-log4j12.jar桥接包包含了SLF4J的StaticLoggerBinder实现,这个实现将SLF4J的调用适配到Log4j 1.x的API上。这意味着即使代码中使用了SLF4J API,日志记录仍然可以通过Log4j 1.x来完成。
对于支持SLF4J的日志实现,如Logback和Log4j 2.x,它们自身就提供了StaticLoggerBinder的实现。例如,Logback的logback-classic.jar和Log4j 2.x的log4j-slf4j-impl.jar模块,都包含了一个符合SLF4J规范的StaticLoggerBinder,使得它们可以直接作为SLF4J的实现。因此不需要额外的桥接包,SLF4J能够识别并使用这些日志实现进行日志记录。
总之,桥接包确保了SLF4J与传统日志框架之间的兼容性,而StaticLoggerBinder则是SLF4J实现其核心功能的关键,即在运行时找到并使用正确的日志实现。
注: 具体有关StaticLoggerBinder底层实现可参考这篇文章。
常用的桥接包:如使用SLF4J的API进行编程,底层想使用log4j1来进行实际的日志输出,这就是slf4j-log4j12干的事。
•slf4j-jdk14: 让SLF4J使用Java内置的日志系统(JUL)。
•slf4j-log4j12: 将SLF4J与Log4j 1.x绑定。
•log4j-slf4j-impl: 绑定SLF4J到Log4j 2。
•logback-classic: SLF4J的实现,使用Logback作为日志引擎。
•slf4j-jcl: 桥接SLF4J到Apache Commons Logging。
3.3 如何从其它日志实现/门面到SLF4J呢?
其实大致的实现就是两步,一是选择SLF4J和具体实现,二是兼容旧的日志实现/门面到SLF4J。
例如项目之前是用的JCL的API,不可能因为要换一个日志框架,把原先的日志代码都改掉吧(API的方法不一样,入参和使用方法也不一样),这个代价太大。 我们希望的是,原有的日志代码可以不动,后续的代码可以用新的SLF4J的API,桥接包就是为了达到这样的效果。具体操作就三步:1、移除掉旧的日志依赖2、引入SLF4J提供的桥接依赖3、项目中引入SLF4J和新的日志实现。
图7 SLF4J相关桥接包依赖
场景介绍:如 使用log4j1的API进行编程,但是想最终通过logback来进行输出,所以就需要先将log4j1的日志输出转交给slf4j来输出,slf4j 再交给logback来输出。将log4j1的输出转给slf4j,这就是log4j-over-slf4j做的事。
•jul-to-slf4j:jdk-logging到slf4j的桥梁,将jul的日志输出切换到slf4j。
•log4j-over-slf4j:log4j1到slf4j的桥梁,将log4j1的日志输出切换到slf4j。
•jcl-over-slf4j:commons-logging到slf4j的桥梁,将commons-logging的底层日志输出切换到slf4j。
注: 更详细的SLF4J和不同日志实现的搭配以及各个日志系统之间的切换所需引用的具体jar包可参考这篇文章。
3.4 桥接包导致的冲突
场景1:jcl-over-slf4j 与 slf4j-jcl 冲突
•jcl-over-slf4j: 这个桥接器的作用是将Apache Commons Logging(JCL)的日志调用转换为SLF4J API。
如果你的代码或依赖项使用了JCL API,但你希望统一日志处理并利用SLF4J的灵活性,可以引入jcl-over-slf4j。这将使得JCL的日志记录调用被重定向到SLF4J,从而可以选择和配置任何SLF4J兼容的日志实现。
•slf4j-jcl: 这个桥接器则是将SLF4J API的调用桥接到Apache Commons Logging。
如果你的项目中使用了SLF4J,但希望日志输出通过Commons Logging处理,可以使用slf4j-jcl。这将SLF4J的日志调用映射到JCL,使得你的日志记录通过Commons Logging的实现进行。
如果这两者共存的话,必然造成相互委托,造成内存溢出
场景2:log4j-over-slf4j 与 slf4j-log4j12 冲突
•log4j-over-slf4j: 这个库的目的是将Log4j 1.x的日志API调用重定向到SLF4J API。
如果你的应用程序原本使用Log4j 1.x进行日志记录,但你想利用SLF4J的灵活性,可以选择使用log4j-over-slf4j。它会模拟Log4j的API,使得Log4j的配置和调用能够透明地转换为SLF4J,这样你就可以在运行时使用任何SLF4J兼容的日志实现,如Logback或Log4j 2。
•slf4j-log4j12: 这个桥接器将SLF4J API的调用绑定到Log4j 1.x实现。
如果你的项目使用了SLF4J API,但希望日志输出通过Log4j 1.x处理,那么可以引入slf4j-log4j12。这样,所有的SLF4J调用都会被转换为Log4j的具体操作。
如果这两者共存的话,理论上必然造成相互委托,造成内存溢出。但是log4j-over-slf4内部做了一个判断,可以防止造成内存溢出。
注意:log4j-over-slf4j库在启动时会进行内部检查,以确保它不会与Log4j 1.x直接使用或者其他SLF4J绑定(如slf4j-log4j12)冲突。它会检查是否存在多个SLF4J绑定,特别是org.slf4j.impl.StaticLoggerBinder的实例,因为这个类是SLF4J用来确定实际日志实现的标志。如果发现多个这样的绑定,log4j-over-slf4j会抛出一个警告或异常,指出类路径中存在冲突,并建议用户清理类路径以避免循环引用或日志记录的不正确行为。 这个检查通常在类加载时执行,即当应用程序启动并尝试加载log4j-over-slf4j时。如果检测到类路径中有其他SLF4J绑定,它会通过org.slf4j.LoggerFactory的静态初始化来抛出错误信息,而不是在运行时导致内存溢出。这种检查机制有助于防止潜在的问题,并指导开发者如何解决日志库的冲突。
场景3:jul-to-slf4j 与 slf4j-jdk14 冲突
•jul-to-slf4j: 这个桥接器的作用是将Java内置的日志框架java.util.logging(JUL)的日志记录调用转换为SLF4J API。
如果你的Java应用使用了JUL API,但希望将日志记录委托给SLF4J,以便于选择和切换不同的日志实现,那么可以引入jul-to-slf4j。这使得JUL的日志记录能够被SLF4J的实现如Logback或Log4j处理。
•slf4j-jdk14: 这个桥接器则刚好相反,它将SLF4J API的调用重定向到JUL。
这意味着,即使你的代码使用SLF4J API,日志记录实际上会通过JDK的java.util.logging框架进行。这通常发生在你有一个使用SLF4J的库,但希望使用JUL作为日志实现的场景。请注意,使用这个桥接器可能会限制你对日志系统的控制和配置,因为JUL通常不如SLF4J的其他实现那样功能丰富。
如果这两者共存的话,必然造成相互委托,造成内存溢出
4. 处理日志包冲突
OK,到现在我们已经清楚地知道日志门面与日志实现的对应关系,以及在多个日志实现jar包存在的情况下如何通过桥接包实现我们期望的最终日志输出效果,那么有没有一种方式能够帮助我们在项目启动的时候只管的发现是否存在日志jar包冲突呢(比如场景2情况能否提前感知呢)? 回答这个问题之前,我们需要先解答下文中最初的问题,为什么同样的应用部署在不同的机器上面会出现不同的表征呢(一台正常打印日志,另一台虽正常启动,但是无任何日志打印)?
4.1 无日志打印原因
答案:因为每个SLF4J的桥接包都有org.slf4j.impl.StaticLoggerBinder,SLF4J则会随机选择一个使用。当选择的跟系统配置的一样时就可以打印日志,否则就打印不出。
查看acccheck应用的pom文件定位对应的jar包,发现同时共存多套日志jar包(图8)。
日志门面: slf4j-api、 commons-logging 日志实现: log4j、logback(logback-classic和logback-core) 桥接包: jcl-over-slf4j、slf4j-log4j12 日志记录配置文件: logback.xml
很明显该应用是通过logback的日志实现方式来进行日志记录的,但是应用中同时引用了日志门面SLF4J和JCL,并且在日志实现中同时引用了log4j和logback,两个桥接包的作用分别是jcl-over-slf4j(commons-logging到slf4j的桥梁,将commons-logging的底层日志输出切换到slf4j),slf4j-log4j12(将SLF4J的日志门面与log4j 1.x日志实现绑定)。
但是日志记录的配置文件是logback.xml,所以当SLF4J绑定到log4j日志实现时,无法正常找到相关配置文件,故而无法输出日志,只有当SLF4J绑定到logback日志实现时才能够正常进行日志打印。
图 8 acccheck应用中应用的相关日志jar包
4.2 解决方案
OK,现在已经明确问题是因为SLF4J绑定到不同的日志实现导致的日志会出现无法记录的表征,并且可以确定需要输出的配置文件是logback.xml,那么处理方式已经很清晰啦。
第一步:首先先确立需要使用的一套日志框架(日志门面+日志实现),在该应用中使用SLF4J+Logback。不难发现满足需求的日志jar包如下。
日志门面: slf4j-api 日志实现: logback(logback-classic和logback-core)
第二步:需要对无用的日志jar包进行去除,在该应用中需要去除掉JCL(该jar包已经通过桥接包 jcl-over-slf4j实现功能替换),去除log4j相关依赖(log4j的日志实现和SLF4J到log4j 1.x的桥接包slf4j-log4j12)。
第三步:需要评估是否存在引用需要共存场景,在该应用中存在JCL日志门面,发现在代码中未直接引用JCL包中的类和接口,因此桥接包 jcl-over-slf4j也无需保留。如果代码中对JCL有直接引用的话可以通过引入桥接包jcl-over-slf4j实现功能替换。
4.3 监控日志jar包冲突
回到本节的问题,那么有没有一种方式能够帮助我们在项目启动的时候只管的发现是否存在日志jar包冲突呢(比如场景2情况能否提前感知呢)? 答案是可以。
注: 由于这块不是本文的重点,大家感兴趣可以参考这篇文章。
5. 总结
通过以上有关日志框架相关知识的介绍以及实践,可以将解决日志框架共存/冲突问题概括为需遵循一下几个原则:
1.明确需要使用的一套日志实现
2.删除多余的无用日志依赖jar包
3.视应用的引用是否必须共存情况引入桥接包
如果有引用必须共存的话,那么就移除原始包,使用“over”类型的包(over类型的包复制了一份原始接口,重新实现)
- 使用日志抽象提供的指定方式
不能over的,使用日志抽象提供的指定方式,例如jboss-logging中,可以通过org.jboss.logging.provider环境变量指定一个具体的日志框架实现
项目里统一了日志框架之后,无论用那种日志框架打印,最终还是走向我们中转/适配后的唯一一个日志框架。解决了共存/冲突之后,项目里就只剩一款日志框架。再也不会出现“日志打不出”,“日志配置不生效”之类的各种恶心问题。
最后补充一张以SLF4J为日志门面的适配方案图(如图9),目前SLF4J是适配方案中最核心的那个框架,也是图9的中心枢纽。只要围绕slf4j做适配/转化,理论上就没有处理不了的冲突。
图 9 SLF4J的适配转化流程图
参考文章
https://www.jianshu.com/p/191a95ad0b89
https://juejin.cn/post/7026757663732006943
https://juejin.cn/post/7239339678372806693?from=search-suggest
https://juejin.cn/post/7032648801122779150?from=search-suggest
https://juejin.cn/post/7211801284709056573?from=search-suggest
https://juejin.cn/post/7137457656255479845?from=search-suggest
https://juejin.cn/post/7159126231235952653?from=search-suggest
https://juejin.cn/post/6942481722856603655?from=search-suggest
https://juejin.cn/post/6945753017878577165
https://juejin.cn/post/6945220055399399455