编年史队列+ log4j2异步记录器 [英] Chronicle queue + log4j2 async logger

问题描述

我使用log4j2 2.10.0并具有以下代码:

   SingleChronicleQueue q = SingleChronicleQueueBuilder.binary(args[0]).blockSize(536870912).build();
    ExcerptAppender a = q.acquireAppender();

    char[] chars = "abcdefghijklmnopqrstuvwxyz".toCharArray();
    StringBuilder sb = new StringBuilder();
    Random random = new Random();
    for (int i = 0; i < 1000; i++) {
        char c = chars[random.nextInt(chars.length)];
        sb.append(c);
    }
    String t = sb.toString();

    for (int i = 0; i < 1000000; i ++ ) {
        m_logger.info(i + " " + t);
        a.writeText(t);
    }

cq4和日志都写入相同的目录.

在日志中，一切都很好，直到我能看到

    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601049 
    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601050 
    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601051 
    12:40:06.156 - [main] INFO c.c.c.a.r.SandboxApp 601052 

有些IO操作使它延迟了6秒.

我对磁盘，安装等不了解.如果我注释掉writeText，但我不知道这是一个编年史问题还是log4j2，它将消失.

我的log4j2参数是

-DLog4jContextSelector = org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -DAsyncLogger.RingBufferSize = 65536 * 65536 -DAsyncLogger.WaitStrategy = Sleep -Dlog4j2.AsyncQueueFullPolicy = Discard -Dlog4j2.DiscardThres

以下是探查器显示的内容

谢谢！

解决方案

一旦开始使用内存映射文件，就离开Java领域，进入操作系统(和硬件)领域.

问题1:您使用的是什么操作系统(以及什么版本)?

问题2:您的计算机上有多少物理内存?

问题3:您使用的是什么硬盘? SSD还是旋转磁盘?

2017年，消费级旋转磁盘的写入速度超过200 MB/秒，速度非常快.相比之下，此2017年比较中最快的SSD写入1900 MB/秒

您确实只是尝试向内存映射文件写入大约2GB.某些时候需要将其与物理磁盘同步.同步过程很容易就需要6秒钟...

具有内存映射文件的欢乐"是您几乎无法控制何时进行同步.人们最终会分割成较小的文件，以确保这些停顿不会变得太大.在调整此类应用程序的性能时，存在一些不可思议的问题.在这个领域有很多东西要学习.欢乐时光即将来临！享受吧！

顺便说一句，您无法配置

-DAsyncLogger.RingBufferSize=65536*65536 # not a number

Log4j2将尝试将65536*65536解析为数字，这将失败，并且会回退以使用默认的缓冲区大小.您需要指定所需的环形缓冲区大小(以字节为单位).

I use log4j2 2.10.0 and have the following code:

   SingleChronicleQueue q = SingleChronicleQueueBuilder.binary(args[0]).blockSize(536870912).build();
    ExcerptAppender a = q.acquireAppender();

    char[] chars = "abcdefghijklmnopqrstuvwxyz".toCharArray();
    StringBuilder sb = new StringBuilder();
    Random random = new Random();
    for (int i = 0; i < 1000; i++) {
        char c = chars[random.nextInt(chars.length)];
        sb.append(c);
    }
    String t = sb.toString();

    for (int i = 0; i < 1000000; i ++ ) {
        m_logger.info(i + " " + t);
        a.writeText(t);
    }

Both the cq4 and the log is writing to the same dir.

And in the log, it was blasting out fine until I can see

    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601049 
    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601050 
    12:40:00.853 - [main] INFO c.c.c.a.r.SandboxApp 601051 
    12:40:06.156 - [main] INFO c.c.c.a.r.SandboxApp 601052 

There's some sort of IO operation that made it delayed 6 seconds.

I don't know enough about disk, mount, etc. This would disappear if I comment out the writeText but I don't know if it's a chronicle problem or log4j2.

My log4j2 parameter is

-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -DAsyncLogger.RingBufferSize=65536*65536 -DAsyncLogger.WaitStrategy=Sleep -Dlog4j2.AsyncQueueFullPolicy=Discard -Dlog4j2.DiscardThreshold=INFO

Here's what the profiler is showing

Thanks!!

解决方案

Once you start to work with memory-mapped files, you leave the realm of Java and enter the world of operating systems (and hardware).

So, question 1: what operating system (and what version) are you using?

Question 2: how much physical memory do you have on your machine?

Question 3: what hard disk are you using? SSD or spinning disk?

In 2017, consumer grade spinning disks exceeding 200 MB/sec write speed are pretty fast. By comparison, the fastest SSD in this 2017 comparison writes 1900 MB/sec.

You did just try to write about 2GB to a memory mapped file. That needs to be sync-ed with the physical disk at some point. That syncing could easily take 6 seconds...

The "joy" with memory mapped files is that you have little control over when this syncing happens. People end up splitting into smaller files to ensure these pauses don't grow too large. There is some aspect of black magic in tuning the performance of this kind of applications. There is a lot to learn in this field. Fun times ahead! Enjoy!

By the way, you cannot configure

-DAsyncLogger.RingBufferSize=65536*65536 # not a number

Log4j2 will try to parse 65536*65536 as a number, which will fail, and it will fall back to use the default buffer size instead. You need to specify the desired ring buffer size in bytes.

这篇关于编年史队列+ log4j2异步记录器的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！