标签：异步 ch qos int log4j2 日志 logback public

Springboot 项目默认使用的是logback 做日志。

在qps 比较高的时候我们希望日志异步打印，同步打印日志可能造成打日志都影响性能。下面研究其用法。

1. logback

0. logback 配置

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!---日志存放位置-->
    <!--
    1. ${user.dir}对应tomcat的bin目录
    2. ${user.home}对应操作系统当前用户目录
    3. ${webApp.root}对应当前应用根目录
    -->
    <property name="LOG_PATH" value="${user.home}/log/"/>
    <!-- 读取spring的application.yaml 的变量 -->
    <springProperty scope="context" name="apppName" source="spring.application.name" />
    <property name="LOG_NAME" value="${apppName}"/>

    <!-- 不带彩色的日志在控制台输出时候的设置 -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <!-- %-5level 代表日志取五个字符，INFO 会变为 INFO加一个空格 -->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <appender name="LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <File>${LOG_PATH}/${LOG_NAME}.log</File>
        <!-- 日志文件的格式 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!-- 格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度 %msg：日志消息，%n是换行符-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | [%thread] %level %logger{50} - %msg%n</pattern>
            <!-- 此处设置字符集，防止中文乱码 -->
            <charset>UTF-8</charset>
        </encoder>
        <!-- 配置日志的滚动时间 ，表示只保留最近 10 天的日志-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 归档的日志文件的路径，例如今天是2013-12-21日志，当前写的日志文件路径为file节点指定，可以将此文件与file指定文件路径设置为不同路径，从而将当前日志文件或归档日志文件置不同的目录。
            而2013-12-21的日志文件在由fileNamePattern指定。%d{yyyy-MM-dd}指定日期格式，%i指定索引 -->
            <fileNamePattern>${LOG_PATH}/${LOG_NAME}_%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <!-- 除按日志记录之外，还配置了日志文件不能超过10M，若超过10M，日志文件会以索引0开始，
      命名日志文件，例如log-2013-12-21.0.log -->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志保留10天-->
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>
    <appender name="LOG_FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <File>${LOG_PATH}/${LOG_NAME}_error.log</File>
        <!-- 日志文件的格式 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!-- 格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | [%thread] %level %logger{50} - %msg%n</pattern>
            <!-- 此处设置字符集，防止中文乱码 -->
            <charset>UTF-8</charset>
        </encoder>
        <!-- 配置日志的滚动时间 ，表示只保留最近 10 天的日志-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 归档的日志文件的路径，例如今天是2013-12-21日志，当前写的日志文件路径为file节点指定，可以将此文件与file指定文件路径设置为不同路径，从而将当前日志文件或归档日志文件置不同的目录。
            而2013-12-21的日志文件在由fileNamePattern指定。%d{yyyy-MM-dd}指定日期格式，%i指定索引 -->
            <fileNamePattern>${LOG_PATH}/${LOG_NAME}_error_%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <!-- 除按日志记录之外，还配置了日志文件不能超过10M，若超过10M，日志文件会以索引0开始，
      命名日志文件，例如log-2013-12-21.0.log -->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志保留10天-->
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>
    <appender name="ASYNC_INFO" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>0</discardingThreshold>
        <queueSize>512</queueSize>
        <appender-ref ref="LOG_FILE" />
    </appender>
    <appender name="ASYNC_ERROR" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>0</discardingThreshold>
        <queueSize>512</queueSize>
        <appender-ref ref="LOG_FILE_ERROR" />
    </appender>
    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="LOG_FILE"/>
<!--        <appender-ref ref="LOG_FILE_ERROR"/>-->
        <!-- 异步日志 -->
        <!--<appender-ref ref="ASYNC_INFO"/>
        <appender-ref ref="ASYNC_ERROR"/>-->
    </root>

    <logger name="cn.qz" level="debug"/>
</configuration>

1. 同步测试

上面的是同步日志的用法，下面研究其同步用法

log.info 打印日志的时候会调用到： ch.qos.logback.core.spi.AppenderAttachableImpl#appendLoopOnAppenders

    public int appendLoopOnAppenders(E e) {
        int size = 0;
        Appender<E>[] appenderArray = (Appender[])this.appenderList.asTypedArray();
        int len = appenderArray.length;

        for(int i = 0; i < len; ++i) {
            appenderArray[i].doAppend(e);
            ++size;
        }

        return size;
    }

获取到的appenderArray 如下：

控制台打印，调用到：

(1). 调用到ch.qos.logback.core.OutputStreamAppender#subAppend 转为byte[]

   protected void subAppend(E event) {
        if (this.isStarted()) {
            try {
                if (event instanceof DeferredProcessingAware) {
                    ((DeferredProcessingAware)event).prepareForDeferredProcessing();
                }

                byte[] byteArray = this.encoder.encode(event);
                this.writeBytes(byteArray);
            } catch (IOException var3) {
                this.started = false;
                this.addStatus(new ErrorStatus("IO failure in appender", this, var3));
            }

        }
    }

    private void writeBytes(byte[] byteArray) throws IOException {
        if (byteArray != null && byteArray.length != 0) {
            this.lock.lock();

            try {
                this.outputStream.write(byteArray);
                if (this.immediateFlush) {
                    this.outputStream.flush();
                }
            } finally {
                this.lock.unlock();
            }

        }
    }

this.outputStream 是ch.qos.logback.core.joran.spi.ConsoleTarget 的内部类。

(2). 调用到ch.qos.logback.core.joran.spi.ConsoleTarget 内部，然后答应

//
// Source code recreated from a .class file by IntelliJ IDEA
// (powered by FernFlower decompiler)
//

package ch.qos.logback.core.joran.spi;

import java.io.IOException;
import java.io.OutputStream;

public enum ConsoleTarget {
    SystemOut("System.out", new OutputStream() {
        public void write(int b) throws IOException {
            System.out.write(b);
        }

        public void write(byte[] b) throws IOException {
            System.out.write(b);
        }

        public void write(byte[] b, int off, int len) throws IOException {
            System.out.write(b, off, len);
        }

        public void flush() throws IOException {
            System.out.flush();
        }
    }),
    SystemErr("System.err", new OutputStream() {
        public void write(int b) throws IOException {
            System.err.write(b);
        }

        public void write(byte[] b) throws IOException {
            System.err.write(b);
        }

        public void write(byte[] b, int off, int len) throws IOException {
            System.err.write(b, off, len);
        }

        public void flush() throws IOException {
            System.err.flush();
        }
    });

    private final String name;
    private final OutputStream stream;

    public static ConsoleTarget findByName(String name) {
        ConsoleTarget[] arr$ = values();
        int len$ = arr$.length;

        for(int i$ = 0; i$ < len$; ++i$) {
            ConsoleTarget target = arr$[i$];
            if (target.name.equalsIgnoreCase(name)) {
                return target;
            }
        }

        return null;
    }

    private ConsoleTarget(String name, OutputStream stream) {
        this.name = name;
        this.stream = stream;
    }

    public String getName() {
        return this.name;
    }

    public OutputStream getStream() {
        return this.stream;
    }

    public String toString() {
        return this.name;
    }
}

文件打印

同样会调用到：调用到ch.qos.logback.core.OutputStreamAppender#subAppend 转为byte[]， this.outputStream 是FileOutputStream，也就是写出文件。

2. 异步测试

将自己日志的包改为异步：

...
    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="LOG_FILE"/>
<!--        <appender-ref ref="LOG_FILE_ERROR"/>-->
        <!-- 异步日志 -->
        <!--<appender-ref ref="ASYNC_INFO"/>
        <appender-ref ref="ASYNC_ERROR"/>-->
    </root>

    <logger name="cn.qz" level="debug">
        <appender-ref ref="ASYNC_INFO"/>
    </logger>
</configuration>

测试：

ch.qos.logback.core.spi.AppenderAttachableImpl#appendLoopOnAppenders 获取到的appendersArray 如下：

继续调用到： ch.qos.logback.core.AsyncAppenderBase#append

调用： ch.qos.logback.core.AsyncAppenderBase#putUninterruptibly

    private void putUninterruptibly(E eventObject) {
        boolean interrupted = false;

        try {
            while(true) {
                try {
                    this.blockingQueue.put(eventObject);
                    return;
                } catch (InterruptedException var7) {
                    interrupted = true;
                }
            }
        } finally {
            if (interrupted) {
                Thread.currentThread().interrupt();
            }

        }
    }

可以看到是往任务队列里面写日志。

注意上面的配置。对于cn.qz 开头的日志会打印两边到文件，因为既满足root 又满足"cn.qz" 单独配置的。

方法：ch.qos.logback.classic.Logger#callAppenders

    public void callAppenders(ILoggingEvent event) {
        int writes = 0;

        for(Logger l = this; l != null; l = l.parent) {
            writes += l.appendLoopOnAppenders(event);
            if (!l.additive) {
                break;
            }
        }

        if (writes == 0) {
            this.loggerContext.noAppenderDefinedWarning(this);
        }

    }

获取到的logger 如下：

正确的配置

对全局的文件日志都异步打印

    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="ASYNC_INFO"/>
<!--        <appender-ref ref="LOG_FILE_ERROR"/>-->
        <!-- 异步日志 -->
        <!--<appender-ref ref="ASYNC_INFO"/>
        <appender-ref ref="ASYNC_ERROR"/>-->
    </root>

<!--    <logger name="cn.qz" level="debug">-->
<!--        <appender-ref ref="ASYNC_INFO"/>-->
<!--    </logger>-->

1》ch.qos.logback.classic.Logger#callAppenders 获取到的logger

2》ch.qos.logback.core.spi.AppenderAttachableImpl#appendLoopOnAppenders 获取的appenderArray

3. 日志的父子logger的概念

ch.qos.logback.classic.Logger#callAppenders 获取到的logger 有父子的概念。

对于这个配置，对于cn.qz 开头的日志，console和文件都会打印两遍。如果cn.qz 的日志级别改为off，则cn.qz 的日志不会打印。

可以理解为日志框架从最底层找(找到底层然后执行日志逻辑)，然后找其父类(子的日志级别会传到父类，如果子的日志级别大于父类会影响父类日志级别，小于父的日志级别则不影响父logger的日志级别)，最顶层的父类是Root。

配置

    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="LOG_FILE"/>
<!--        <appender-ref ref="LOG_FILE_ERROR"/>-->
        <!-- 异步日志 -->
        <!--<appender-ref ref="ASYNC_INFO"/>
        <appender-ref ref="ASYNC_ERROR"/>-->
    </root>

    <logger name="cn.qz" level="debug">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="ASYNC_INFO"/>
    </logger>

比如上面配置：获取到的logger的父子关系如下(包名(日志级别))

cn.qz(DEBUG) -》 cn(null) -》ROOT(INFO)

那么对于cn.qz 开头的日志，日志级别为INFO以上的日志会走cn.qz 的设置和ROOT的设置(打印两次)。DEBUG会走cn.qz的设置(一次)。

2. log4j2

参考： https://blog.csdn.net/loveLifeLoveCoding/article/details/127037559

Log4j2中的异步日志实现方式有AsyncAppender和AsyncLogger两种。其中，AsyncAppender采用了ArrayBlockingQueue来保存需要异步输出的日志事件；AsyncLogger则使用了Disruptor框架来实现高吞吐。

	AsyncAppender 会调用到： org.apache.logging.log4j.core.appender.AsyncAppender#append
	AsyncLogger会调用到： org.apache.logging.log4j.core.async.AsyncLoggerConfig#log

标签：异步,ch,qos,int,log4j2,日志,logback,public
From： https://www.cnblogs.com/qlqwjy/p/17297646.html

logback&log4j2异步日志