使用log4j2免费分配日志记录

介绍

最近，我正在为一个客户端工作，试图为大型精心制作的Java系统消除一些GC暂停。 经过分析后，我意识到大部分垃圾都是通过日志记录产生的！ 是否有一种简单的方法来删除所有分配？ 原来有:)

我应该使用哪个框架进行GC免费日志记录？

让我们将注意力转向使用哪个日志记录框架的古老问题。

通常的候选人是

log4j2
登入
java.util.logging
slf4j（简单）

并且除非您正在做一些超级时髦的事情，否则您可能不会认为这会给您带来很大的改变。

已经进行了许多比较性能的研究，如果您在超低等待时间的竞技场中玩，那当然很重要。（请参阅对Java日志记录框架进行基准测试）

但是我担心的是分配！

请参阅我之前关于分配的弊端的文章“性能优化的第一条规则”。

在典型的系统中，所有分配的30％-50％可以记录在日志中！因此，即使大多数人不介意在一个框架中进行日志记录的时间比在另一个框架中花费几毫秒的时间，他们几乎肯定会在乎日志框架所产生的垃圾导致的长时间GC暂停。

而且所有这些日志记录分配都可以通过简单的配置删除。从2.6开始的Log4J2是免费分配的，因此没有任何借口不利用它:)

让我们看看它的作用

提出免分配索赔是一回事，但让我们看看这在实践中是否成立。

考虑下面的这个简单的日志记录代码：请注意，我在代码中使用了slf4j，因此只需更改配置即可在不同的日志记录框架中运行。这样做是个好主意，因为尽管log4j2可能是目前最好的框架，但谁知道明天会带来什么……

package test;import org.slf4j.Logger;
import org.slf4j.LoggerFactory;import java.util.List;
import java.util.stream.Collectors;
import java.util.stream.IntStream;public class GCLogger {private final static Logger LOGGER = LoggerFactory.getLogger(GCLogger.class);public static void main(String[] args) throws InterruptedException {List<String> list = IntStream.range(0,(int)1e6).mapToObj(i->"" + i).collect(Collectors.toList());//Log 1 million lines in a loop sleeping 1 second between each iteration of the loop//to allow time to run Flight Recorder.for (int i = 0; i < 1000; i++) {list.forEach(s->LOGGER.info("Logging [{}]", s));Thread.sleep(1000);}}
}

使用log4j2运行–无分配

如果我们使用以下Maven配置将程序配置为与log4j2一起运行：

<dependency><groupId>org.slf4j</groupId><artifactId>slf4j-api</artifactId><version>1.7.25</version>
</dependency>
<dependency><groupId>org.apache.logging.log4j</groupId><artifactId>log4j-api</artifactId><version>2.9.1</version>
</dependency>
<dependency><groupId>org.apache.logging.log4j</groupId><artifactId>log4j-core</artifactId><version>2.9.1</version>
</dependency>
<dependency><groupId>org.apache.logging.log4j</groupId><artifactId>log4j-slf4j-impl</artifactId><version>2.9.1</version>
</dependency>

我们使用此log4j2配置

xml version="1.0" encoding="UTF-8" ?><Configuration status="INFO"><Appenders><Console name="Console" target="SYSTEM_OUT"><PatternLayout pattern="%d{HH:mm:ss:SSS} [%t] %-5level %logger[36] %msg%n"></PatternLayout></Console><File name="MyFile" fileName="all.log" immeadiateFlush="false" append="false"><PatternLayout pattern="%d{dd MMM yyyy HH:mm:ss,SSS} [%t] %-5level %logger[36] %msg%n"></PatternLayout></File></Appenders><Loggers><Root level="debug"><AppenderRef ref="MyFile"></AppenderRef></Root></Loggers>
</Configuration>

然后我们得到0分配！

我们可以通过在程序上运行Flight Recorder来证明这一点（见下文）：

唯一分配的内存归因于Flight Recorder（可以通过配置FR的方式来避免这种情况发生）。

使用登录运行

使用Logback尝试完全相同。

使用此Maven配置

<dependency><groupId>ch.qos.logback</groupId><artifactId>logback-classic</artifactId><version>1.2.3</version>
</dependency>

使用此注销配置：

<configuration><appender name="FILE" class="ch.qos.logback.core.FileAppender"><file>myApp.log</file><encoder><pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern></encoder></appender><appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"><encoder><pattern>%msg%n</pattern></encoder></appender><root level="debug"><appender-ref ref="FILE" /></root>
</configuration>

当我们使用Flight Recorder运行时，我们会看到一个拥抱量分配！