Java Native Memory在Log4j2中被使用了吗？我发现很多日志存储在本地内存而不是堆中。

Question

我们有一个Java应用程序，通过运行Main函数启动，同时在Springboot中嵌入Jetty作为Web容器。我发现Java堆达到最大大小，但堆使用率很低，并且Java由于耗尽本地内存而被操作系统杀死。

在pmap中有许多64MB的内存。我转储了一些内存块，并在其中发现了许多日志。这些日志的时间各不相同，即使过了几天仍然存在于内存中。例如：

2019-03-23T05:50:46,851 661258664 [xxxxxx] INFO
2019-03-27T06:00:12,040 1029308155 [xxxxxxxx] INFO .........

我们使用log4j2和slf4j作为日志工具。日志由名称以“qtp”开头的jetty线程打印。 我们设置了immediateFlush="false" 和 SizeBasedTriggeringPolicy size="10MB"

我不知道为什么日志内容不在堆内存中。是log4j2在缓存或写入日志时使用Java本机内存吗？log4j2会出现内存泄漏吗？

- FFMan

Answer 1

我猜你所看到的是Log4j 2的一个鲜为人知的功能的副作用：无垃圾日志记录。

自从log4j 2.6版本以来，该库极其小心地在稳定状态下记录日志时不分配任何临时对象（在初始化和配置期间会有一些临时对象的分配）。

其他没有此功能的日志记录库通常会分配许多LogEvent对象以及字符串、char[]数组和byte[]数组。这些通常都是非常短暂的，并且很快就会被回收，但大量的日志记录将填满年轻代并导致晋升。

在HotSpot JVM上，即使是次要收集也需要暂停整个应用，这适用于所有当前的GC算法：串行、并行、并发、CMS和G1。（随着Shenandoah和ZGC的出现，这可能会减少影响，但这些收集器在撰写本文时仍处于实验阶段。另请注意，Zing/Azul有一个无暂停收集器，但该工作尚未贡献给OpenJDK。）

Log4j 2通过避免分配和尽可能重用内存来规避这个问题。

- Remko Popma

---

倒数第二段是不正确的，而且已经错误了超过20年。 - user207421

@user207421 你的观点基于什么？你可以通过启用-XX:+PrintGCApplicationStoppedTime标志来轻松验证HotSpot中的小型收集是停顿全局的。随着应用堆越来越大，存活对象越来越多，这正迅速成为一个重要问题。 - Remko Popma

链接的页面并没有提到如何使用堆外内存。 - Thilo

我猜这是堆栈内存，但我可能错了。应用程序是否使用内存映射文件附加器？ - Remko Popma

@Remko Popma 内存映射文件 appender？你是指 RollingRandomAccessFile appender 吗？我们正在使用 RollingRandomAccessFile appender。我阅读了你的链接并检查了源代码。ByteBuffer 在 appender 中被使用。但是当应用程序运行时似乎没有内存泄漏，它只使用和重复使用 256K 的本地内存。所以我怀疑自己是否正确。但是许多日志内容都在内存块中。 - FFMan

@FFMan 我想知道你是否在使用log4j 2 MemoryMappedFileAppender，感谢澄清。所以我猜你最终是通过内存转储来处理log4j使用的缓冲区。但我可能错了。不确定这里是否真的存在问题。 - Remko Popma