03月28, 2019

关于异步log4j2中location信息打印问题

“For the Horde!Lok’tar Ogar!”(为了部落,不胜则亡) alt

背景

项目改造过程中将log4j2改成异步,发现行号没有打印,于是扒了下官方文档,大概陈述下:

先说一下这个问题是怎么解决的,然后稍微扩展一下其他配置,有兴趣的可以往下看或者溜一遍官方文档

解决

标签中配置includeLocation="true"。

扩展

log4j2在异步记录日志中引入了两个技术:

  • 异步日志记录器:它能够很快将Logger的调用返回到应用程序,而且提供全异步和混合异步两种模式。

  • LMAX Disruptor:这个是记录器内部的一个组件(所以使用log4j2需要引入disruptor包),它是一个无锁的线程间通信库,不是队列,这样的话能够保证高吞吐和低延迟。

下面大体说一下两种异步模型及需要注意的几点:

全异步

有两种实现方式(其实是一种方式的两种形式):

1、将系统属性log4j2.contextSelector设置 为

org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

System.setProperty("log4j2.contextSelector,"org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");

2、在启动时配置启动参数设置:

-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

注意:

如果用AsyncLoggerContextSelector实现全异步,那么配置中就要使用

还有一点就是如果配置了这个属性,并且使用了 ,那么程序将会产生两个线程:日志数据首先传递给线程A,然后线程A再传递给线程B,最后再输出到磁盘,这样虽然也是可行的,但是中间多了一步线程交互的过程,其实没有必要。

贴上一个官方给出的不需要location信息的配置文件示例:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Appenders>
<!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<RandomAccessFile name="RandomAccessFile" fileName="async.log" immediateFlush="false" append="false">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern>
</PatternLayout>
</RandomAccessFile>
</Appenders>
<Loggers>
<!--不需要打印location信息-->
<Root level="info" includeLocation="false">
<AppenderRef ref="RandomAccessFile"/>
</Root>
</Loggers>
</Configuration>
同步异步混合

比起全异步,混合异步反而更灵活,但是与全异步记录器相比性能略有下降。实现方式是使用 or 配置在指定记录器上,但是只能配一个根记录器( 元素),可以组合异步和非异步记录器。比如,包含 元素的配置文件还可以包含同步记录器的 元素。

贴一个官方给出的混合异步的配置例子:

<Configuration status="WARN">
<Appenders>
<!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
immediateFlush="false" append="false">
<PatternLayout>
<Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
</PatternLayout>
</RandomAccessFile>
</Appenders>
<Loggers>
<!-- pattern layout actually uses location, so we need to include it -->
<AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</AsyncLogger>
<Root level="info" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</Root>
</Loggers>
</Configuration>
对于location信息

默认情况下,异步日志记录器不会将location信息传递给I/O线程,如果你的layouts或custom过滤器需要location信息,你需要在所有相关日志记录器(包括根日志记录器)的配置中设置“includeLocation=true”。

如果其中一个layouts配置了关于位置的信息,比如HTML locationInfo,或者表达式%C或%class、%F或%file、%l或%location、%L或%line、%M或%method。

log4j2将会获取堆栈的快照(snapshot),并遍历堆栈跟踪以查找位置信息,因此会消耗较多的时间。比同步logger慢1.3-5倍,同步日志记录器在获取堆栈快照之前会等待尽可能长的时间,如果不需要位置,那么快照将永远不会被捕获。

贴一个官方给出的各种日志记录包异步吞吐量比较图,可以看出log4j2的全异步和混合异步日志记录器吞吐量比其他记录器高很多。 alt

题外话(补充两个常用的小功能)

1、additivity:这个属性的意思是需不需要打印此logger继承的父logger,如果是false则只打印当前logger;如果是true则继续打印上一层的logger,直到root。

2、实现error日志打印双份:info.log中打印一份(即info中包括info和error日志),error.log中打印一份(只包括error日志),这样的好处是能根据error日志出现的上下文快速定位到程序bug出现的位置,这个功能需要使用过滤器实现,比如:

<RollingFile name="error" fileName="${log_home}/error.log" immediateFlush="false"
append="true" filePattern="/history/error-%d{yyyy-MM-dd}.log.gz">
<Filters>
<!--只允许级别为error的日志通过-->
<ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<PatternLayout charset="UTF-8">
<Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} #| %p #| %t #| %c{-1}:%L #| %m%n</Pattern>
</PatternLayout>
<Policies>
<!--默认打印周期为一天-->
<TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies>
<!--保存日志个数为15个-->
<DefaultRolloverStrategy max="15"/>
</RollingFile>

扫鸭扫鸭,求关注

alt

本文链接:http://blog.keepting.cn/blog//post/关于异步log4j2中location信息打印问题.html

-- EOF --

Comments