分享

探索Java日志的奥秘: 底层日志系统

 苏心阁 2019-10-07

log4j2是apache在log4j的基础上,参考logback架构实现的一套新的日志系统(我感觉是apache害怕logback了)。

log4j2的官方文档上写着一些它的优点:

在拥有全部logback特性的情况下,还修复了一些隐藏问题

API 分离:现在log4j2也是门面模式使用日志,默认的日志实现是log4j2,当然你也可以用logback(应该没有人会这么做)

性能提升:log4j2包含下一代基于LMAX Disruptor library的异步logger,在多线程场景下,拥有18倍于log4j和logback的性能

多API支持:log4j2提供Log4j 1.2, SLF4J, Commons Logging and java.util.logging (JUL) 的API支持

避免锁定:使用Log4j2 API的应用程序始终可以选择使用任何符合SLF4J的库作为log4j-to-slf4j适配器的记录器实现

自动重新加载配置:与Logback一样,Log4j 2可以在修改时自动重新加载其配置。与Logback不同,它会在重新配置发生时不会丢失日志事件。

高级过滤: 与Logback一样,Log4j 2支持基于Log事件中的上下文数据,标记,正则表达式和其他组件进行过滤。

插件架构: Log4j使用插件模式配置组件。因此,您无需编写代码来创建和配置Appender,Layout,Pattern Converter等。Log4j自动识别插件并在配置引用它们时使用它们。

属性支持:您可以在配置中引用属性,Log4j将直接替换它们,或者Log4j将它们传递给将动态解析它们的底层组件。

Java 8 Lambda支持

自定义日志级别

产生垃圾少:在稳态日志记录期间,Log4j 2 在独立应用程序中是无垃圾的,在Web应用程序中是低垃圾。这减少了垃圾收集器的压力,并且可以提供更好的响应时间性能。

和应用server集成:版本2.10.0引入了一个模块log4j-appserver,以改进与Apache Tomcat和Eclipse Jetty的集成。

Log4j2类图:

这次从四个地方去探索源码:启动,配置,异步,插件化

源码探索

启动

log4j2的关键组件

LogManager

根据配置指定LogContexFactory,初始化对应的LoggerContext

LoggerContext

1、解析配置文件,解析为对应的java对象。

2、通过LoggerRegisty缓存Logger配置

3、Configuration配置信息

4、start方法解析配置文件,转化为对应的java对象

5、通过getLogger获取logger对象

Logger

LogManaer

该组件是Log4J启动的入口,后续的LoggerContext以及Logger都是通过调用LogManager的静态方法获得。我们可以使用下面的代码获取Logger

Logger logger = LogManager.getLogger;

可以看出LogManager是十分关键的组件,因此在这个小节中我们详细分析LogManager的启动流程。

LogManager启动的入口是下面的static代码块:

这段静态代码段主要分为下面的几个步骤:

首先根据特定配置文件的配置信息获取loggerContextFactory

如果没有找到对应的Factory的实现类则通过ProviderUtil中的getProviders方法载入providers,随后通过provider的loadLoggerContextFactory方法载入LoggerContextFactory的实现类

如果provider中没有获取到LoggerContextFactory的实现类或provider为空,则使用SimpleLoggerContextFactory作为LoggerContextFactory。

根据配置文件载入LoggerContextFactory

在这段逻辑中,LogManager优先通过配置文件”log4j2.component.properties”通过配置项”log4j2.loggerContextFactory”来获取LoggerContextFactory,如果用户做了对应的配置,通过newCheckedInstanceOf方法实例化LoggerContextFactory的对象,最终的实现方式为:

在默认情况下,不存在初始的默认配置文件log4j2.component.properties,因此需要从其他途径获取LoggerContextFactory。

通过Provider实例化LoggerContextFactory对象

代码:

这里比较有意思的是hasProviders和getProviders都会通过线程安全的方式去懒加载ProviderUtil这个对象。跟进lazyInit方法:

再看构造方法:

这里的懒加载其实就是懒加载Provider对象。在创建新的providerUtil实例的过程中就会直接实例化provider对象,其过程是先通过getClassLoaders方法获取provider的类加载器,然后通过loadProviders(classLoader);加载类。在providerUtil实例化的最后,会统一查找”META-INF/log4j-provider.properties”文件中对应的provider的url,会考虑从远程加载provider。而loadProviders方法就是在ProviderUtil的PROVIDERS列表中添加对一个的provider。可以看到默认的provider是org.apache.logging.log4j.core.impl.Log4jContextFactory

LoggerContextFactory = org.apache.logging.log4j.core.impl.Log4jContextFactory

Log4jAPIVersion = 2.1.0

FactoryPriority= 10

很有意思的是这里懒加载加上了锁,而且使用的是

lockInterruptibly这个方法。lockInterruptibly和lock的区别如下:

lock 与 lockInterruptibly比较区别在于:

lock 优先考虑获取锁,待获取锁成功后,才响应中断。

lockInterruptibly 优先考虑响应中断,而不是响应锁的普通获取或重入获取。

ReentrantLock.lockInterruptibly允许在等待时由其它线程调用等待线程的

Thread.interrupt 方法来中断等待线程的等待而直接返回,这时不用获取锁,而会抛出一个InterruptedException。 ReentrantLock.lock方法不允许Thread.interrupt中断,即使检测到Thread.isInterrupted,一样会继续尝试获取锁,失败则继续休眠。只是在最后获取锁成功后再把当前线程置为interrupted状态,然后再中断线程。

上面有一句注释值得注意:

原来这里是为了让osgi可以阻止启动。

再回到logManager:

可以看到在加载完Provider之后,会做factory的绑定:

到这里,logmanager的启动流程就结束了。

配置

在不使用slf4j的情况下,我们获取logger的方式是这样的:

Logger logger = logManager.getLogger(xx.class)

跟进getLogger方法:

这里有一个getContext方法,跟进,

上文提到factory的具体实现是Log4jContextFactory,跟进getContext

方法:

直接看start:

发现其中的核心方法是reconfigure方法,继续跟进:

可以看到每一个configuration都是从ConfigurationFactory拿出来的,我们先看看这个类的getInstance看看:

这里可以看到ConfigurationFactory中利用了PluginManager来进行初始化,PluginManager会将ConfigurationFactory的子类加载进来,默认使用的XmlConfigurationFactory,JsonConfigurationFactory,YamlConfigurationFactory这三个子类,这里插件化加载暂时按下不表。

回到reconfigure这个方法,我们看到获取ConfigurationFactory实例之后会去调用getConfiguration方法:

跟进getConfiguration,这里值得注意的是有很多个getConfiguration,注意甄别,如果不确定的话可以通过debug的方式来确定。

这里就会根据之前加载进来的factory进行配置的获取,具体的不再解析。

回到reconfigure,之后的步骤就是setConfiguration,入参就是刚才获取的config

这个方法最重要的步骤就是config.start,这才是真正做配置解析的

这里面有如下步骤:

获取日志等级的插件

初始化

初始化Advertiser

配置

先看一下初始化,也就是setup这个方法,setup是一个需要被复写的方法,我们以XMLConfiguration作为例子,

发现这里面有一个比较重要的方法constructHierarchy,跟进:

发现这个就是一个树遍历的过程。诚然,配置文件是以xml的形式给出的,xml的结构就是一个树形结构。回到start方法,跟进doConfiguration:

发现就是对刚刚获取的configuration进行解析,然后塞进正确的地方。回到start方法,可以看到昨晚配置之后就是开启logger和appender了。

异步

AsyncAppender

log4j2突出于其他日志的优势,异步日志实现。我们先从日志打印看进去。找到Logger,随便找一个log日志的方法。

一路跟进

可以看出这个在打日志之前做了调用次数的记录。跟进tryLogMessage,

继续跟进:

这里可以看到在实际打日志的时候,会从config中获取打日志的策略,跟踪ReliabilityStrategy的创建,发现默认的实现类为DefaultReliabilityStrategy,跟进看实际打日志的方法

这里实际打日志的方法居然是交给一个config去实现的。。。感觉有点奇怪。。跟进看看

可以清楚的看到try之前是在创建LogEvent,try里面做的才是真正的log(好tm累),一路跟进。

接下来就是callAppender了,我们直接开始看AsyncAppender的append方法:

这里主要的步骤就是:

生成logEvent

将logEvent放入BlockingQueue,就是transfer方法

如果BlockingQueue满了则启用相应的策略

同样的,这里也有一个线程用来做异步消费的事情

直接看run方法:

阻塞获取logEvent

将logEvent分发出去

如果线程要退出了,将blockingQueue里面的event消费完在退出。

AsyncLogger

直接从AsyncLogger的logMessage看进去:

跟进logWithThreadLocalTranslator,

这里的逻辑很简单,就是将日志相关的信息转换成RingBufferLogEvent(RingBuffer是Disruptor的无所队列),然后将其发布到RingBuffer中。发布到RingBuffer中,那肯定也有消费逻辑。这时候有两种方式可以找到这个消费的逻辑。

找disruptor被使用的地方,然后查看,但是这样做会很容易迷惑

按照Log4j2的尿性,这种Logger都有对应的start方法,我们可以从start方法入手寻找

在start方法中,我们找到了一段代码:

final RingBufferLogEventHandler[] handlers = {new RingBufferLogEventHandler};

disruptor.handleEventsWith(handlers);

直接看看这个RingBufferLogEventHandler的实现:

顺着接口找上去,发现一个接口:

通过注释可以发现,这个onEvent就是处理逻辑,回到RingBufferLogEventHandler的onEvent方法,发现里面有一个execute方法,跟进:

这个方法就是实际打日志了,AsyncLogger看起来还是比较简单的,只是使用了一个Disruptor。

插件化

之前在很多代码里面都可以看到

final PluginManager manager = new PluginManager(CATEGORY);

manager.collectPlugins(pluginPackages);

其实整个log4j2为了获得更好的扩展性,将自己的很多组件都做成了插件,然后在配置的时候去加载plugin。

跟进collectPlugins。

处理逻辑如下:

从Log4j2Plugin.dat中加载所有的内置的plugin

然后将OSGi Bundles中的Log4j2Plugin.dat中的plugin加载进来

再加载传入的package路径中的plugin

最后加载配置中的plugin

逻辑还是比较简单的,但是我在看源码的时候发现了一个很有意思的东西,就是在加载log4j2 core插件的时候,也就是

PluginRegistry.getInstance.loadFromMainClassLoader

这个方法,跟进到decodeCacheFiles:

可以发现加载时候是从一个文件(PLUGIN_CACHE_FILE)获取所有要获取的plugin。看到这里的时候我有一个疑惑就是,为什么不用反射的方式直接去扫描,而是要从文件中加载进来,而且文件是写死的,很不容易扩展啊。然后我找了一下PLUGIN_CACHE_FILE这个静态变量的用处,发现了PluginProcessor这个类,这里用到了注解处理器。

/**

* Annotation processor for pre-scanning Log4j 2 plugins.

*/@SupportedAnnotationTypes('org.apache.logging.log4j.core.config.plugins.*')public class PluginProcessor extends AbstractProcessor { // TODO: this could be made more abstract to allow for compile-time and run-time plugin processing

(不太重要的方法省略)

我们可以看到在process方法中,PluginProcessor会先收集所有的Plugin,然后在写入文件。这样做的好处就是可以省去反射时候的开销。

然后我又看了一下Plugin这个注解,发现它的RetentionPolicy是RUNTIME,一般来说PluginProcessor是搭配RetentionPolicy.SOURCE,CLASS使用的,而且既然你把自己的Plugin扫描之后写在文件中了,RetentionPolicy就没有必要是RUNTIME了吧,这个是一个很奇怪的地方。

小结

总算是把Log4j2的代码看完了,发现它的设计理念很值得借鉴,为了灵活性,所有的东西都设计成插件式。互联网技术日益发展,各种中间件层出不穷,而作为工程师的我们更需要做的是去思考代码与代码之间的关系,毫无疑问的是,解耦是最具有美感的关系。

    本站是提供个人知识管理的网络存储空间,所有内容均由用户发布,不代表本站观点。请注意甄别内容中的联系方式、诱导购买等信息,谨防诈骗。如发现有害或侵权内容,请点击一键举报。
    转藏 分享 献花(0

    0条评论

    发表

    请遵守用户 评论公约

    类似文章 更多