日志输出性能优化-缓存、异步

最新推荐文章于 2023-03-24 20:28:19 发布

架构师夏老师

最新推荐文章于 2023-03-24 20:28:19 发布

阅读量1.5k

点赞数 1

分类专栏： JavaSE

JavaSE 专栏收录该内容

11 篇文章 0 订阅

订阅专栏

笔者负责的一个集成接口平台的应用，其业务功能并不复杂，但是要重点考虑接口的性能。
在进行过异步数据库写入、第三方代码调优、报文解析调优后，基本上已经无可优化性能的代码了。但是在JProfiler的监控里面又发现了logback日志的可优化空间。

问题描述：
下图中可看出logback的日志输出占了64%的cpu消耗，目标就是优化它！

优化方案：
1. 这部分写日志的代码写了一些报文数据，确实是比较大的字符串。先禁掉控制台输出，生产环境也不需要控制台输出，写日志文件即可。
配置中去掉控制台输出
<rootlevel="INFO">

<appender-refref="ASYNC_ROLLING_FILE"/>
</root>
优化后的结果，915ms直接变为76ms，优化效果相当显著

2. 可能这时有人会说了，“你控制台禁了，日志文件又禁不了，不还是慢啊！”这话很有道理，但是logback有个好东东，日志文件异步写入
配置如下：
<appendername="ASYNC_ROLLING_FILE"class="ch.qos.logback.classic.AsyncAppender">
<appender-refref="ROLLING_FILE"/>
</appender>
<rootlevel="INFO">
<appender-refref="ASYNC_ROLLING_FILE"/>
</root>
所以在上面的性能监控里面就看不到文件写入的性能消耗

1、log4j已成为大型系统必不可少的一部分，log4j可以很方便的帮助我们在程序的任何位置输出所要打印的信息，便于我们对系统在调试阶段和正式运行阶段对问题分析和定位。由于日志级别的不同，对系统的性能影响也是有很大的差距，日志级别越高，性能越高。

2、log4j主要分为error,warn,info,debug四个级别，也是使用最多的四种，日志级别从左至右依次增加。

3、log4j对系统性能的影响程度主要体现在以下几方面：
  a、日志输出的目的地，输出到控制台的速度比输出到文件系统的速度要慢。
   b、日志输出格式不一样对性能也会有影响，如简单输出布局(SimpleLayout)比格式化输出布局(PatternLayout)输出速度要快。可以根据需要尽量采用简单输出布局格式输出日志信息。
   c、日志级别越低输出的日志内容就越多，对系统系能影响很大。
   d、日志输出方式的不同，对系统系能也是有一定影响的，采用异步输出方式比同步输出方式性能要高。
   e、每次接收到日志输出事件就打印一条日志内容比当日志内容达到一定大小时打印系能要低。

4、针对以上几点对系能的影响中的第4,5点，对日志配置文件做如下配置：
   a、设置日志缓存，以及缓存大小

Java代码

log4j.appender.A3.BufferedIO=true
#Buffer单位为字节，默认是8K，IO BLOCK大小默认也是8K
log4j.appender.A3.BufferSize=8192

  以上配置说明，当日志内容达到8k时，才会将日志输出到日志输出目的地。

b、设置日志输出为异步方式

Java代码

<appender name="DRFOUT" class="org.apache.log4j.DailyRollingFileAppender">
<param name="File" value="logs/brws.log" />
<param name="Append" value="true" />
<param name="DatePattern" value="yyyy_MM_dd'.'" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d [%t] %-5p %l %x - %m%n" />
</layout>
</appender>
<appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">
<param name="BufferSize" value="512" />
<appender-ref ref="DRFOUT" />
</appender>

同步情况：各线程直接获得输出流进行输出(线程间不需要同步)。
异步情况：1.各线程将日志写到缓存，继续执行下面的任务(这里是异步的)

2.日志线程发现需要记日志时独占缓存(与此同时各线程等待，此时各线程是被阻塞住的)，从缓存中取出日志信息，获得输出流进行输出，将缓存解锁(各线程收到提醒，可以接着写日志了)

   众所周知，磁盘IO操作、网络IO操作、JDBC操作等都是非常耗时的，日志输出的主要性能瓶颈也就是在写文件、写网络、写JDBC的时候。日志是肯定要记的，而要采用异步方式记，也就只有将这些耗时操作从主线程当中分离出去才真正的实现性能提升，也只有在线程间同步开销小于耗时操作时使用异步方式才真正有效！

    现在我们接着分别来看看这几种记录日志的方式：

    a、将日志记录到本地文件同样都是写本地文件Log4j本身有一个buffer处理入库，采用异步方式并不一定能提高性能(主要是如何配置好缓存大小)；而线程间的同步开销则是非常大的！因此在使用本地文件记录日志时不建议使用异步方式。
    b、将日志记录到JMS JMS本身是支持异步消息的，如果不考虑JMS消息创建的开销，也不建议使用异步方式。
   c、将日子记录到SOCKET 将日志通过Socket发送，纯网络IO操作不需要反馈，因此也不会耗时
    d、将日志记录到数据库众所周知JDBC是几种方式中最耗时的：网络、磁盘、数据库事务，都使JDBC操作异常的耗时，在这里采用异步方式入库倒是一个不错的选择。
   e、将日志记录到SMTP 同JDBC

5、异步输出日志工作原理
   AsyncAppender采用的是生产者消费者的模型进行异步地将Logging Event送到对应的Appender中。

a、生产者：外部应用了Log4j的系统的实时线程，实时将Logging Event传送进AsyncAppender里

b、中转：Buffer和DiscardSummary

c、消费者：Dispatcher线程和appenders
工作原理：

1） Logging Event进入AsyncAppender，AsyncAppender会调用append方法，在append方法中会去把logging Event填入Buffer中，当消费能力不如生产能力时，AsyncAppender会把超出Buffer容量的Logging Event放到DiscardSummary中，作为消费速度一旦跟不上生成速度，中转buffer的溢出处理的一种方案。

2） AsyncAppender有个线程类Dispatcher，它是一个简单的线程类，实现了Runnable接口。它是AsyncAppender的后台线程。

Dispatcher所要做的工作是：

① 锁定Buffer，让其他要对Buffer进行操作的线程阻塞。

② 看Buffer的容量是否满了，如果满了就将Buffer中的Logging Event全部取出，并清空Buffer和DiscardSummary；如果没满则等待Buffer填满Logging Event，然后notify Disaptcher线程。

③ 将取出的所有Logging Event交给对应appender进行后面的日志信息推送。

以上是AsyncAppender类的两个关键点：append方法和Dispatcher类，通过这两个关键点实现了异步推送日志信息的功能，这样如果大量的Logging Event进入AsyncAppender，就可以游刃有余地处理这些日志信息了。

************************************************************************************************************************************************************************

不久前在系统中完成了监控的功能，监控系统的信息量很大，用户对页面的每一个点击都会产生记录，每天下来的日志量有2G多，我用log4j把这些监控记录放在日志里，然后进行异步处理，但即使是这样，记录日志会对磁盘IO产生频繁的访问，而IO通常就是系统的瓶颈所在。于是对log4j配置进行一些调优就成了必要。下面是我系统中的

架构师夏老师

关注

1
点赞
踩
2

收藏

觉得还不错? 一键收藏
0
评论
日志输出性能优化-缓存、异步

笔者负责的一个集成接口平台的应用，其业务功能并不复杂，但是要重点考虑接口的性能。在进行过异步数据库写入、第三方代码调优、报文解析调优后，基本上已经无可优化性能的代码了。但是在JProfiler的监控里面又发现了logback日志的可优化空间。问题描述：下图中可看出logback的日志输出占了64%的cpu消耗，目标就是优化它！优化方案：1. 这部分写日志的代码写了一些报文数据，确...
复制链接

扫一扫