专栏首页泛泛聊后端Log4j2日志框架

Log4j2日志框架

log4j2是一个比较新的日志框架,作为log4j的升级版本,修复了它的锁竞争问题提升了性能,提供了丰富的组件支持以及良好的语义配置。

如何使用

同样使用SLF4J来作为日志门面,需要引入以下依赖。

<properties>
    <log4j2.version>2.13.1</log4j2.version>
</properties>

<dependencies>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>${log4j2.version}</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>${log4j2.version}</version>
    </dependency>
</dependencies>

编写配置文件,log4j2的配置文件相对其他的日志框架层次比较分明。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="LogToConsole" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} [%level] [%thread] [%logger{15}] \: %m%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="LogToConsole"/>
        </Root>
    </Loggers>
</Configuration>

Appenders标签包含了所有的日志输出目的地,每个Appender都包含在其中,如上述代码声明的Console也是比较具备语义性的。Loggers标签包含了所有的日志输出器,同样也是突出了语义性。

package com.lihongkun.labs.log4j2;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * Hello world!
 */
public class Application {

    private static final Logger LOGGER = LoggerFactory.getLogger(Application.class);

    public static void main(String[] args) {
        LOGGER.info("Hello World");
    }
}

// 输出为
2020-04-25 16:33:45 [INFO] [main] [com.lihongkun.labs.log4j2.Application] : Hello World

组件

log4j2在组件上的概念和logback一样都是继承自log4j,基本上没有什么差别。最大的差别在于其中的扩展实现。除了一些常见的Appender,比如日志文件大小和日期滚动,JDBC,邮件等等。它还对一些开源日志采集或者存储中间件进行了比较多的支持如flume-ng、kafka、mongodb等等,官方原生支持使用起来不用费一些力气去扩展。更多丰富的功能可参考 http://logging.apache.org/log4j/2.x/manual/appenders.html

异步

log4j最大的诟病就是在多线程环境下,锁竞争激烈,严重拖慢了应用。而升级版的log4j2提供了两种异步日志的方式:

  1. AsyncAppender。 内部使用的一个队列(ArrayBlockingQueue)和一个后台线程,日志先存入队列,后台线程从队列中取出日志。 阻塞队列容易受到锁竞争的影响,当更多线程同时记录时性能可能会变差。
  2. AsyncLogger。 内部使用的是LMAX Disruptor技术,Disruptor是一个无锁的线程间通信库,它不是一个队列,不需要排队,从而产生更高的吞吐量和更低的延迟。

AsyncAppender

这个组件在logback和log4j2 都是存在的,对比下它们的性能。

使用同样的代码进行基准测试,并通过调整@Threads的值调整测试的线程数,来测试不同并发线程下他们的性能表现。

public static void main(String[] args) throws RunnerException {
    Options opt = new OptionsBuilder()
            .include(Log4j2Jmh.class.getSimpleName())
            .forks(1)
            .warmupIterations(1)
            .measurementIterations(5)
            .build();

    new Runner(opt).run();
}

@Benchmark
@Threads(32)
public void async(){
    LOGGER.info("hello world");
}

测试机器情况

  • 64位 windows 10
  • 8GB内存
  • Intel(R) Core(TM) i7-4510U @2.00GHz 2.60GHz

logback的日志文件异步配置如下

<Configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>logback-lab.log</file>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] [%-5level] [%logger{30}] - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="FILE"/>
    </appender>
    <root level="INFO">
        <appender-ref ref="ASYNC_FILE" />
    </root>
</Configuration>

吞吐表现异步比同步高了一个数量级,数据如下

线程数

FileAppender

AsyncAppender

1

229,312

7,538,561

2

138,359

4,879,026

4

115,662

3,948,502

8

136,350

4,018,552

16

133,302

4,040,151

32

122,303

4,084,070

log4j2的异步日志配置文件如下,采用了同样的输出格式。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <File name="default" fileName="log4j2-lab.log">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%thread] [%-5level] [%logger{30}] - %msg%n"/>
        </File>
        <Async name="defaultAsync">
            <AppenderRef ref="default"/>
        </Async>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="defaultAsync"/>
        </Root>
    </Loggers>
</Configuration>

结果和官方的性能测试相悖,log4j2的异步比logback差距了一个数量级。

线程数

log4j2

logback

1

186,722

7,538,561

2

156,574

4,879,026

4

112,581

3,948,502

8

105,942

4,018,552

16

98,952

4,040,151

32

99,801

4,084,070

AsyncLogger

它的开启方式有两种,一种是通过配置文件直接指定Logger是异步的,可以做到一部分异步,一部分是同步,相对灵活。比如官网是在做性能测试的时候是这么配置的,只有com.foo.Bar是异步的。

<?xml version="1.0" encoding="UTF-8"?>

<!-- No need to set system property "log4j2.contextSelector" to any value
     when using <asyncLogger> or <asyncRoot>. -->

<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>

另外一种是直接通过命令行选项开启全部logger异步,无需额外配置。

<!-- 使用jvm参数-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -->

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <RandomAccessFile name="default" fileName="log4j2-lab.log" immediateFlush="false" append="false">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%thread] [%-5level] [%logger{30}] - %msg%n"/>
        </RandomAccessFile>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="default"/>
        </Root>
    </Loggers>
</Configuration>

无论是哪一种方式去开启AsyncLogger都需要引入 disruptor的依赖。

<dependency>
  <groupId>com.lmax</groupId>
  <artifactId>disruptor</artifactId>
  <version>3.4.2</version>
</dependency>

通过测试,吞吐的表现比log4j2 的 AsyncAppender 好很多但是和 logback的AsyncAppender相比还是差了一个数量级。

logback的性能数据和log4j2官方给出的相近,而log4j2的性能数据却和官方给出的差距非常大。这点就让人很迷惑了。http://logging.apache.org/log4j/2.x/manual/async.html 这是官方对应同步和异步性能测试的参考数据。

本文分享自微信公众号 - 泛泛聊后端(HelloBackend),作者:李鸿坤

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2020-05-06

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • SHELL命令分组统计

    这是一个真实的面试题,目的在考察SEHLL基础的使用。对于这个日志所需要关注的信息只有IP和URL。

    李鸿坤
  • 大型项目的依赖包管理

    Java的世界里,几乎所有项目的包管理都是使用了Maven,或者在其之上演进的组件。大型项目比如有成百上千个工程,依赖的包比较多,如果没有统一的版本管理,很容易...

    李鸿坤
  • 微基准测试框架JMH

    最典型的场景就是你想知道两个功能相同的操作到底哪个性能比较好,通常会自己手撸一段代码,前后增加时间,然后对比多次执行的时间。这种做法比较原始,还要自己处理预热等...

    李鸿坤
  • TiKV 源码解析系列文章(十八)Raft Propose 的 Commit 和 Apply 情景分析

    在学习了 前面的文章 之后,相信大家已经对 TiKV 使用的 Raft 核心库 raft-rs 有了基本的了解。raft-rs 实现了 Raft Leader ...

    PingCAP
  • TiKV 源码解析系列文章(十八)Raft Propose 的 Commit 和 Apply 情景分析

    在学习了 前面的文章 之后,相信大家已经对 TiKV 使用的 Raft 核心库 raft-rs 有了基本的了解。raft-rs 实现了 Raft Leader ...

    CNCF
  • 如何使用oracle自动分区管理数据仓库?

    1. 为什么使用自动分区? 在oracle11g之前,oracle是不支持自动分区功能的,这就可能导致我们系统在运行一段时间之后,就需要看看分区是否创建或者写...

    用户5166556
  • PHP常用函数总结

    $x = 5.7; $y = 1.3; // 两个浮点数,x>y 浮点余数 $r = fmod($x, $y); // $r equals 0.5, becau...

    V站CEO-西顾
  • 走近源码:Redis跳跃列表究竟怎么跳

    在前面介绍压缩列表ziplist的时候我们提到过,zset内部有两种存储结构,一种是ziplist,另一种是跳跃列表skiplist。为了彻底理解zset的内部...

    Jackeyzhe
  • 空间转录组学(Spatial Transcriptomics)

    前面给大家简单的科普了空间转录组,可能还是有些人对背后的技术原理有些疑惑,那么我们深入的探讨一下技术原理。文末有视频会更直观。

    用户7627119
  • 机器学习中如何解决过拟合

    机器学习中出现的非常频繁的问题:过拟合与规则化。我们先简单的来理解下常用的L0、L1、L2和核范数规则化。 监督机器学习问题无非就是"minimizeyour...

    用户1332428

扫码关注云+社区

领取腾讯云代金券