Log4j性能调优，及原理

最新推荐文章于 2024-03-11 07:51:38 发布
最新推荐文章于 2024-03-11 07:51:38 发布
阅读量269 收藏 1
点赞数
文章标签： 数据结构与算法 java 操作系统
原文链接：https://my.oschina.net/xpbug/blog/414794
版权

为什么80%的码农都做不了架构师？>>>   hot3.png

问题背景

证券的交易系统，整个系统使用SEDA并发架构。最近为系统添加了新模块，合规风控。由于是新模块，且需求刚起步，为了追求开发速度，开发初期并没有太注意编程细节。在做性能测试的时候，发现合规系统一个线程每秒只能处理10个订单。这跟单线程每秒1000个订单的距离相差遥远。

SEDA并发架构在吞吐上没有任何问题，但编程细节不注意，也会对性能造成致命影响。所以，我需要对合规系统做Profiling，找到性能瓶颈，并加以改进。

并发模型以及Logger对其影响

  1. Thread-Based-Concurrency(TBC)

  2. Event-Driven-Concurrency(EDC)

  3. Staged-Event-Driven-Architecture(SEDA)

  4. Actor

  5. LMAX Disruptor

TBC最常见的就是BIO的web server，如BIO的tomcat。每一个HTTP请求都是一个线程。TBC的优点是处理大型复杂事务。比如事务中存在大量阻塞IO。Logger的性能对TBC的吞吐和延迟影响并不大。但线程创建开销大，线程的上下文切换开销也大，对共享内存编程的技术要求比较高，很容易出错。

TBC后面的几个模型均属于Event-Sourcing类型。一个非典型场景是NIO的web server，比如Jetty，NIO tomcat。NIO的web server在socket处理上使用了事件驱动模型，但对http request还是使用thread模型。典型场景则是很多交易系统所用的SEDA模型。事件驱动模型的特点是将任何的请求或状态变化均变为event，并将event分为几种状态，每种状态的event用少量的线程甚至是单线程去处理，线程和线程之间会传送处理好的event。

事件驱动模型在互联网高并发设计中非常火。而SEDA和Actor则是不相上下的最优方案。而Disruptor的核心优势是线程之间的消息传递机制，跟BlockingQueue相比，其吞吐是BQ的6倍左右，而延迟是BQ的0.16%. 具体比较见https://github.com/LMAX-Exchange/disruptor/wiki/Performance-Results 。所以，生产者消费者模式的消息传递使用Disruptor是一个很好的方案。

因为事件驱动模型中线程数量是有限的，所以需要让线程充分利用CPU，让CPU满负荷跑动起来，任何的IO阻塞，Logger的性能，均会影响系统的吞吐和延迟。例如在事件驱动模型中，假设一个线程一秒钟可以处理100万个单子，也就是一秒钟处理100万个事件，如果每个事件处理过程中，发生了IO阻塞或者Logger开销，即使是1us的开销，100万个事件合在一起就是1s，这使得系统的吞吐立马下降到50万每秒，性能缩水一半。所以，事件驱动模型的事件处理线程中，要消除跟业务计算无关的CPU消耗，比如IO，Logger。

合规系统调优

系统说明

此合规系统是SEDA中的某一个stage处理系统，Java编写，单线程，跟其它线程消息传递使用LinkedBlockingQueue，使用log4j 1.2.7打日志。在logger调优之前，已经做了去IO的优化。接下来的调优可以使用Disruptor替换BQ。这部分并不打算在本文中阐述。本文主要关注的是Logger的调优。

Log4j调优前

log4j的配置：

log4j.appender.dailyRolling=org.apache.log4j.DailyRollingFileAppender  
log4j.appender.dailyRolling.ImmediateFlush=true
log4j.appender.dailyRolling.File=/datayes/trading/compliance/log/ComplianceServer.log
log4j.appender.dailyRolling.layout=org.apache.log4j.PatternLayout
log4j.appender.dailyRolling.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] [%-5p] %c - %m %n

使用jvisualvm做profiling, 得出的结果：

131510_eQHc_254689.png

通过上图可以看到，logger的CPU开销占到了当前线程总CPU开销的90%以上。主要原因是因为log4j使用了ImmediateFlush和同步IO。

增加IO Buffer

首先想到的改进方法是给Logger增加IO Buffer，并开启flush cache。

log4j.appender.dailyRolling=org.apache.log4j.DailyRollingFileAppender  
log4j.appender.dailyRolling.ImmediateFlush=false
log4j.appender.dailyRolling.BufferedIO=ture
log4j.appender.dailyRolling.BufferSize=8192
log4j.appender.dailyRolling.File=/datayes/trading/compliance/log/ComplianceServer.log
log4j.appender.dailyRolling.layout=org.apache.log4j.PatternLayout
log4j.appender.dailyRolling.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] [%-5p] %c - %m %n

Flush cache控制logger的缓存，logger待缓存满了，再一次性提交给appender。 BufferedIO控制Appender的缓存，appender待缓存满了，才一次性写入硬盘。

132456_ZMuk_254689.png

经过优化以后，log4j的开销下降到线程CPU开销的80%左右。还是不理想。

升级log4j2

上面的优化并不理想，现在的突破口就是讲logger的运算变为异步，放入另一个线程处理，从而净化业务逻辑运算线程。log4j 1.2.7存在AsyncAppender，可以将Appender写硬盘变为异步。但经过调研，发现在log4j2中，出现了AsyncLogger，可以将logger变为异步。这样连logger的运算也可以踢出本线程。

此外，AsyncLogger使用的线程通信是Disruptor，而AsyncAppender使用的是BlockingQueue，所以AsyncLogger性能又高了一大截。

AsyncLogger的性能比较可以查看 https://logging.apache.org/log4j/2.x/manual/async.html 

使用AsyncLogger

log4j2的配置为：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="info">
  <Appenders>
    <RollingFile name="dailyRolling" fileName="/datayes/trading/compliance/log/ComplianceServer.log" 
        filePattern="/datayes/trading/compliance/log/ComplianceServer.log.%d{yyyy-MM-dd}">
      <PatternLayout>
        <Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] [%-5p] %c - %m %n</Pattern>
      </PatternLayout>
      <Policies>
         <TimeBasedTriggeringPolicy />
      </Policies>
    </RollingFile>
  </Appenders>
  <Loggers>
    <asyncRoot level="info" includeLocation="true">
      <AppenderRef ref="dailyRolling" level="info"/>
    </asyncRoot>
  </Loggers>
</Configuration>

java初始化log4j2，使用非classpath下的xml。

    public static void config(String configXmlPath) {
        if (configXmlPath==null) return;
        try {
            LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
            ctx.setConfigLocation(new File(configXmlPath).toURI());
            ctx.reconfigure();						
        } catch (Exception e) {
            System.out.println("Can not initialize log4j2 with config "+ configXmlPath);
            e.printStackTrace();
            System.exit(1);
        }
    }

优化后的结果：

134305_2a17_254689.png

Log4j的开销降到了线程CPU时间的50%左右。最大的开销是disruptor的锁机制。

优化Disruptor

Disruptor比BQ快的原因有以下这么几点：

  1. 去锁。使用CAS。锁竞争会使CPU跳出当前线程，回归到操作系统层面来判断锁的赢家，这导致大量上下文切换，上下文切换也会导致CPU cache失效。所以锁是一个开销很大的机制。Java中CAS的实现在Atomic包里。

  2. 使用RingBuffer数据结构，避免Q的动态分配，垃圾回收。

  3. 避免多核CPU内存伪共享问题。

具体请参考https://lmax-exchange.github.io/disruptor/ 

从前面的优化结果可以看到，系统已经在使用AsyncLogger和Disruptor，但却还在使用锁机制。这是因为Disruptor提供了3种等待机制：Block，Sleep，Yield。而AsyncLogger默认使用的是Block策略。Block还是用的锁机制。三种等待策略的解释：https://github.com/LMAX-Exchange/disruptor/wiki/Getting-Started#basic-tuning-options 

修改Disruptor等待机制：

    public static void config(String configXmlPath) {
        String strategy = System.getProperty("AsyncLoggerConfig.WaitStrategy");
        if (!("Sleep".equalsIgnoreCase(strategy) || "Block".equalsIgnoreCase(strategy) || "Yield".equalsIgnoreCase(strategy))) {
            System.out.println("Set disruptor wait strategy to sleep");
            System.setProperty("AsyncLoggerConfig.WaitStrategy", "Sleep");
        }
        if (configXmlPath==null) return;
        try {
            LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
            ctx.setConfigLocation(new File(configXmlPath).toURI());
            ctx.reconfigure();                        
        } catch (Exception e) {
            System.out.println("Can not initialize log4j2 with config "+ configXmlPath);
            e.printStackTrace();
            System.exit(1);
        }
    }

修改以后的结果：

142527_e4NA_254689.png

锁等待策略的开销没有了。但calcLocation的时间还是很高。

关闭CalcLocation

任何一个logger的计算location开销都不容忽视。计算location是将当前栈信息做快照，然后计算找到info，debug等方法的具体调用位置。详细内容：https://logging.apache.org/log4j/2.x/manual/async.html#Location 

在我的日志中，并不需要栈信息，只需要打印一个类全名，不需要calcLocation。将includeLocation改为false。最后测试：

143443_eABQ_254689.png

log4j的开销已经不足6%了。

到此，logger的优化完成。

Logger的几个调用方法优化

坏性能好性能
logger.info(“Hi “+user+”, where is “+other);logger.info(“Hi {}, where is {}”, user, other);
logger.error(exception.toString());logger.error(“”, exception);
logger.debug(String.format(“The number is %d”, num));logger.debug(“The number is {}”, num);

左边的劣势有2：

  1. 在本线程中做message的计算。增加额外开销。

  2. 如果没有开启debug，logger.debug也会调用String.format方法，浪费时间。

右边的好处是将参数封装以后提交给Appender，appender会对消息做format。


转载于:https://my.oschina.net/xpbug/blog/414794

weixin_33812433
关注
  • 0
    点赞
  • 踩
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
[springboot]使用log4j2异步日志提升性能
m0_54850825的博客
06-21 1118
同步日志的业务流程处理和日志打印是在同一个线程，日志打印的过程实际上是写文件IO的过程，这个过程是相对耗时的，并且会阻塞主线程的执行，只有日志打印完成后才会继续执行业务处理代码。如果日志量比较大，会影响主业务流程的处理效率。异步日志实现方式：将日志存入一个单独的队列中，有一个单独的线程从队列中获取日志并写入磁盘文件。Log4j2基于LMAX公司开发Disruptor（一个开源的无锁并发框架），改善了Log4j和Logback在架构设计方面的缺陷，具有超高的吞吐量和低延迟。所以我们想获取log4j2异步日志带
Log4j性能调优
cuker919的专栏
04-18 5204
<br />    不久前在系统中完成了监控的功能，监控系统的信息量很大，用户对页面的每一个点击都会产生记录，每天下来的日志量有2G多，我用log4j把这些监控记录 放在日志里，然后进行异步处理，但即使是这样，记录日志会对磁盘IO产生频繁的访问，而IO通常就是系统的瓶颈所在。于是对log4j配置进行一些调优就 成了必要。下面是我系统中的log4j配置： log4j.rootLogger=ERROR,fileout,stdout<br />log4j.logger.monitorLogger=INFO,m
Log4j优化
燕窝
06-17 638
一个经常引用的依靠于logging的参数是可以计算的花费。这是一个合理的概念，一个适度的应用程序可能产生成千上万个日志请求。许多努力花在测量和调试logging的优化上。Log4j要求快速和弹性：速度最重要，弹性是其次。用户应该注意随后的优化建议。日志为禁用时，日志的优化当日志被彻底的关闭，一个日志请求的花费等于一个方法的调用加上整数的比较时间。在2
log4j配置优化
MeiGe在路上。。。
05-14 1108
a、日志输出的目的地，输出到控制台的速度比输出到文件系统的速度要慢。   b、日志输出格式不一样对性能也会有影响，如简单输出布局(SimpleLayout)比格式化输出布局(PatternLayout)输出速度要快。可以根据需要尽量采用简单输出布局格式输出日志信息。 c、日志级别越低输出的日志内容就越多，对系统系能影响很大。 d、日志输出方式的不同，对系统系能也是有一定影响的，
Log4j2效率测试源码
04-10
- **阅读源码**：通过阅读和理解测试源码，可以深入掌握Log4j2的工作原理和性能调优技巧。 - **动手实践**：自己编写测试用例，模拟不同的日志场景，对比不同配置下的性能差异。 通过这份"Log4j2效率测试源码"，...
log4j系统日志
04-16
此外，标签中提到的“源码”部分，意味着我们可以深入研究Log4j的源代码，了解其实现原理，这对于理解日志框架的工作机制和优化日志处理性能非常有帮助。同时，通过阅读源码，开发者可以更好地进行二次开发，或者...
阿里巴巴Java性能调优实战（2021华山版）
05-19
8. **日志和监控**：配置合适的日志框架，如Log4j、SLF4J，进行性能指标监控（如使用JMX、VisualVM、JProfiler等工具），及时发现和解决问题。 9. **资源复用**：利用Java的缓存机制（如Guava Cache、...
action-in-java-performance-tuning:一本关于 Java 性能调优的书
07-09
8. **日志与监控**：通过日志分析工具（如Log4j、Logback）收集性能数据，并使用性能监控工具（如VisualVM、JProfiler）进行实时诊断，可以帮助识别性能瓶颈。 9. **代码优化**：编写高效且可读性强的代码，避免...
simple-log-analyzer:简单的日志分析器。 log4j 解析器 --> 便于搜索的数据库等
06-15
- **性能调优**：通过日志分析发现性能瓶颈，优化代码。 - **安全审计**：检查日志中的安全事件，预防和应对安全威胁。 7. **技术实现** 作为一款基于Java的工具，"simple-log-analyzer"利用Java强大的IO和字符...
log4j2性能优化
qq_36754960的博客
06-24 2689
背景：最近在做log4j升级到Log4j2的项目，在测试升级之后的性能时，被惊了一下，性能没有提升，反而下降了，赶紧研究了一下log4j2的相关配置，以下是研究结果。 1.使用FileAppender的时候，配置若是ImmediateFlush=true，一旦有新日志写入，立马将日志写入到磁盘的文件中。当日志很多，这种频繁操作文件显然性能很低下。 2.不要使用Location相关属性，例如 C or $class, %F or %file, %l or %location, %L or %l..
log4j2 提升系统性能
Just Do It!
01-29 540
什么是log4j2 使用方式 log4j2最好的地方就是异步日志模式,所以在这里我们就要进行升级改造. 日志接口(slf4j) slf4j是对所有日志框架制定的一种规范、标准、接口，并不是一个框架的具体的实现，因为接口并不能独立使用，需要和具体的日志框架实现配合使用(如log4j、logback) 日志实现(log4j、logback、log4j2) log4j是apache实现的一个开源日志组件 logback同样是由log4j的作者设计完成的，拥有更好的特性，用来取代log4..
Log4j日志配置详解 及 性能优化分析
黄豆红豆
03-23 709
大家在进行应用系统 开发时不可避免地要使用到一些日志框架 进行日志记录，比如开发阶段的调试信息、运行时的日志记录及审计。日志是应用软件中不可缺少的部分，Apache的开源项目log4j是一个功能强大的日志组件,提供方便的日志记录。在apache网站： http://logging.apache.org/log4j/1.2/download.html 点击打开链接可以免费下载到Log4j最新版本的
Log4j如何支持多线程环境？你如何优化Log4j的性能？
最新发布
Aaron的博客
03-11 922
在生产环境中，通常建议将日志级别设置为INFO或更高，以避免输出大量的DEBUG和TRACE级别日志，从而减少I/O操作和磁盘空间的使用。Log4j 2.x 版本引入了异步日志记录功能，通过使用异步 Appender 或将 Logger 配置为异步模式，可以显著提高多线程应用程序的日志记录性能。通过实现自己的Appender，你可以控制日志消息的格式、输出目标以及如何处理日志消息，从而实现更高效的日志记录。使用异步Appender可以将日志记录的I/O操作与应用程序的主线程分离，从而提高应用程序的性能。
log4j2性能提升点
weixin_36098377的博客
10-09 1243
1、log4j1写日志多线程情况是阻塞的，log4j2不会阻塞，生产者只负责生产，通过无锁队列ringbuffer的无阻塞内存队列作为缓冲（即使用Disruptor），多生产者多线程的竞争是通过CAS实现，性能较高，至于最后落地，虽然两者都会调用synchronized方法写入日志，log4j2的asynclogger支持多个消费者，每个消费者取一批待处理的日志，类似于分段，用于提高性能 2、D...
log4j性能优化
迷途小书僮
07-20 186
在log4j1.2的版本里，发现有两把性能低下的锁，一把就是在Category的callAppender方法里，代码如下 public void callAppenders(LoggingEvent event) { int writes = 0; for(Category c = this; c != null; c=c.parent) { // ...
log4j2性能分析+原理
qq_31443653的博客
07-27 3448
官方解释： Log4j 2包含基于LMAX Disruptor库的下一代异步记录器。在多线程场景中，异步记录器的吞吐量比Log4j 1.x和Logback高18倍，延迟低。有关详细信息，请参阅异步日志记录性能否则，Log4j 2明显优于Log4j 1.x，Logback和java.util.logging，尤其是在多线程应用程序中 LMAX Disruptor技术。异步记录器在内部使用Di...
log4j2日志戳引发的优化
cyang的博客
05-26 650
log4j2异步打印日志戳传递，深入了解底层传输原理。
log4j2的高并发死锁问题配置优化
文武艺的专栏
03-07 4949
Maven中pom.xml引用&lt;log4j2.version&gt;2.7&lt;/log4j2.version&gt;版本以上&lt;!-- log4j2 高并发造成死锁 --&gt; &lt;dependency&gt; &lt;groupId&gt;org.apache.logging.log4j&lt;/groupId&gt; &lt;artifactId&gt;lo
graylog 性能调优
07-24
对于Graylog的性能调优，以下是一些建议和最佳实践： 1. 硬件资源：确保Graylog服务器具有足够的硬件资源，包括CPU、内存和磁盘空间。根据你的日志流量和数据存储需求，调整硬件配置。 2. JVM调优：Graylog是基于...

“相关推荐”对你有帮助么？

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值