使用log4j2写入日志的Spring Boot太慢

Question

我在Spring Boot应用程序中使用log4j2来简化日志记录。这是我的配置log4j2-dev.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" monitorInterval="30">
<Properties>
    <Property name="LOG_PATTERN">%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight{%5p}--[%T-%-15.15t] [%-20X{serviceMessageId}]%-40.40c{1.} :%m%n%ex</Property>
</Properties>
<Appenders>
    <Console name="ConsoleAppender" target="SYSTEM_OUT"
        follow="true">
        <PatternLayout pattern="${LOG_PATTERN}" />
    </Console>
    <!-- Rolling File Appender -->
    <RollingFile name="FileAppender" fileName="logs/app.log"
        filePattern="logs/app-%d{yyyy-MM-dd}-%i.log">
        <PatternLayout>
            <Pattern>${LOG_PATTERN}</Pattern>
        </PatternLayout>
        <Policies>
            <SizeBasedTriggeringPolicy size="100MB" />
        </Policies>
        <DefaultRolloverStrategy max="10" />
    </RollingFile>
    <Kafka name="KafkaAppender" topic="ServiceCentrallog">
        <Property name="bootstrap.servers">10.2.16.2:9092,10.2.16.3:9092,10.2.16.4:9092</Property>
        <JSONLayout compact="true" properties="true">
            <KeyValuePair key="application"
                value="${bundle:application-dev:spring.application.name}" />
        </JSONLayout>
    </Kafka>
</Appenders>
<Loggers>
    <AsyncRoot level="info">
        <AppenderRef ref="ConsoleAppender" />
        <AppenderRef ref="FileAppender" />
        <AppenderRef ref="KafkaAppender" />
    </AsyncRoot>
</Loggers>

我在项目中的基本类

public abstract class BaseObject {
protected final org.apache.logging.log4j.Logger logger = LogManager.getLogger(getClass());

@Override
public String toString() {
    ObjectMapper mapper = new ObjectMapper();
    mapper.configure(SerializationFeature.FAIL_ON_EMPTY_BEANS, false);
    String jsonString = "";
    try {
        jsonString = mapper.writeValueAsString(this);
    } catch (JsonProcessingException e) {
        logger.error("BaseObject: ", e);
        jsonString = "Can't build json from object";
    }
    return jsonString;
}
}

以下是我如何编写日志：

logger.info("Input: " + input.toString());
....
logger.info("output: " + Utils.toJson(restRes));

它在正常情况下工作正常。但是，如果我使用Jmetter发送大量请求（总计：7996，平均：98条消息/秒），我会发现日志记录速度太慢，在停止发送请求大约1.5分钟后，日志记录仍在继续，日志文件的容量仍在增加。

我已经搜索了很多，但仍然不知道如何加快日志记录，或者找出我的配置中不合理的地方。

Answer 1

但是，如果我使用Jmetter发送大量请求（总计：7996，平均：98条消息/秒），我会发现日志记录速度太慢，在停止发送请求大约1.5分钟后，日志记录仍在继续，日志文件的容量仍在增加。

您正在使用Log4J2的异步日志记录。其目的是在日志记录操作期间不阻塞正在执行的线程。因此，如果您的应用程序在几分钟内记录了许多事情（7996*98条消息），那么这种行为完全有意义：消息排队越来越多，处理这些消息直到最后一条消息需要时间。

我已经搜索了很多，但仍然不知道如何加快日志记录，或者找出我的配置中不合理的地方。

1） 使用同步日志记录将加快您的日志记录速度，因为它将使用阻塞方法：日志记录调用仅在消息将有效地记录在appender中时才会返回，但它也会影响您的处理速度。

2） 此场景中不要使用3个追加器（即记录请求/响应）：

<AsyncRoot level="info">
    <AppenderRef ref="ConsoleAppender" />
    <AppenderRef ref="FileAppender" />
    <AppenderRef ref="KafkaAppender" />
 </AsyncRoot>

它执行日志三次。很多
如果您确实需要记录这些信息，请将其记录在一个附加器中。您可以通过过滤器功能轻松实现这一点（MarkerFilter应该很好）
例如，在登录时添加标记JSON\u REQUEST\u RESPONSE，并指定只有一个appender记录它（如果存在），其他appender在任何情况下都不记录：

<RollingFile name="FileAppender" fileName="logs/app.log"
    filePattern="logs/app-%d{yyyy-MM-dd}-%i.log">
  <!-- ACCEPT Marker-->
  <MarkerFilter marker="JSON_REQUEST_RESPONSE" onMatch="ACCEPT" />
  <...>
</RollingFile>

<Console name="ConsoleAppender" target="SYSTEM_OUT"
    follow="true">
  <!-- DENY Marker-->
  <MarkerFilter marker="JSON_REQUEST_RESPONSE" onMatch="DENY" />
  <...>
</Console>

3） 不要在info（）中过多地登录：

logger.info("Input: " + input.toString());
....
logger.info("output: " + Utils.toJson(restRes));

顺便说一下，不要使用级联进行日志记录，因为如果日志记录器级别不匹配并且没有记录任何内容，这可能会免费昂贵。
在这种情况下，采用供应商的懒惰计算方法更好：

logger.info("Input: {}", () -> input.toString());
....
logger.info("output: {}", () -> Utils.toJson(restRes));