前言
前面几篇“日志那些事儿”讲解了日志的重要性和相关使用。以slf4j+logback的使用为例,我们的步骤为:
- 在工程中引入slf4j、logback相关Jar包
- 编写配置文件logback.groovy/logback.xml等
- 使用LoggerFactory.getLogger()得到logger使用。
从上面可以看出使用过程中非常重要的一个部分为编写配置文件logback.xml,配置文件中通常是配置我们所需要的appender和相关的logger,例如说配置console输出或者配置文件输出等。
一次需求和一次bug
一次需求
前段时间做过一次需求,要求的是尽量无侵入的输出某些请求参数到日志中,Web框架是Webx,在web层采用了valve实现了类似切片功能,在service层直接使用了aop。当然这些都不算关键,关键在于要尽量少的侵入应用,并且要在多个系统中使用。由于在不同应用中可能使用了不同类型的日志框架,所以将关键的aop逻辑、日志输出逻辑封装在client jar中,供应用系统使用。
一次bug
起因
前两天需要对系统升级某项功能,需要引入一个新的jar,升级完成在日常测试环境中部署够,服务功能正常,但是却发现一个非常严重的bug——所有的日志全部不输出了。经排查之后发现是引入的新client jar中使用了slf4j+log4j2,而原应用中使用的是slf4j+logback。前者中引入log4j2-slf4j-impl,后者中的logback-classic中都用org.slf4j.impl.StaticLoggerBinder.class,所以会发生multiple_bindings的错误,按照slf4j的官方文档的说明:
NOTE The warning emitted by SLF4J is just that, a warning. Even when multiple bindings are present, SLF4J will pick one logging framework/implementation and bind with it. The way SLF4J picks a binding is determined by the JVM and for all practical purposes should be considered random. As of version 1.6.6, SLF4J will name the framework/implementation class it is actually bound to.
由于两个StaticLoggerBinder.class属于同名同包,按照hotspot的Jvm规范,会加载classpath下靠前的那个jar中的StaticLoggerBinder。
If the 2 classes have the same package name, i.e. com.mycompany.Client, then you end up in a situation where it is somewhat arbitrary which version of Client is loaded. It comes down to which is on the classpath first. This is a JAR hell situation.
所以,日志停止输出的原因很肯定是因为slf4j binding到了log4j-slf4j-impl中的StaticLoggerBinder,而没有使用logback进行输出。
解决
分析了原因,解决起来了就很简单了,暴力exclude了引入的client jar包中的log4j2相关依赖。重新部署验证后发现日志可以输出,问题解决
对于slf4j的思考
这样做虽然解决了问题,但是并不完美。因为client jar包中引入了log4j2,并且配置了log4j2.xml的配置文件,本意肯定是想使用log4j2输出相关日志到自己指定文件,但是由于我暴力干掉了log4j2,client想输出日志到指定文件是不可能的了,client会将其日志输出到应用主日志中。
当系统中出现两个及以上StaticLoggerBinder.class的时候,肯定不算是“最佳实践”。日志系统虽多,择其善者而从之。
对于client jar设计的思考
一次需求,一次bug,其实都与日志系统相关。这次bug的根本原因也算是因为client jar没有考虑到使用者的感受,把log4j2强加给使用者。client jar可能会有一些记录日志的需求,例如记录一些信息用于调试。那么当client jar有日志输出需求,如何更好地进行设计呢?
我觉得得从以下几个方面考虑:
- 缩小jar包依赖范围,如果是基于maven,可以把client工程中依赖的日志相关jar scope设置为provided.
- “感知”应用系统所使用的日志框架,匹配相应的日志框架
- 不使用配置文件,改用编码配置logger
对于第二点,client jar必须要“感知”应用系统所使用的日志框架,例如究竟是使用了log4j还是log4j2,还是slf4j+logback,亦或者slf4j+log4j等,这样才可以知道client jar中可以使用哪些日志api。对于第三点,由于我们一般都通过xml等配置文件配置日志logger,但这种方式很不灵活。要适配多少种日志系统,就需要在client jar的classpath下放置多少种日志配置文件,而且没法在运行时指定appender,设置layout等等。
总结
如果在client jar中有日志输出的需求,一定要好好设计,千万不能坑了使用者。下篇文章将围绕如何设计包含日志输出的client jar。