配置为 false 的时候，堆栈是这个样子的：
"Thread-0" #27 [18152] prio=5 os_prio=0 cpu=0.00ms elapsed=5.68s tid=0x000002c1fa120e00 nid=0x46e8 runnable [0x000000eda8efe000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@17-loom/Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(java.base@17-loom/LockSupport.java:410) at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:136) at com.lmax.disruptor.MultiProducerSequencer.next(MultiProducerSequencer.java:105) at com.lmax.disruptor.RingBuffer.publishEvent(RingBuffer.java:524) at org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor.enqueue(AsyncLoggerConfigDisruptor.java:379) at org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor.enqueueEvent(AsyncLoggerConfigDisruptor.java:330) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.logInBackgroundThread(AsyncLoggerConfig.java:159) at org.apache.logging.log4j.core.async.EventRoute$1.logMessage(EventRoute.java:46) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.handleQueueFull(AsyncLoggerConfig.java:149) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.logToAsyncDelegate(AsyncLoggerConfig.java:136) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.log(AsyncLoggerConfig.java:116) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82) at org.apache.logging.log4j.core.Logger.log(Logger.java:162) at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2190) at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144) at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127) at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2003) at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1975) at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1312)
对于这种情况，我们需要监控。
首先想到的是进程外部采集系统指标监控：现在服务都提倡上云，并实现云原生服务。对于云服务，存储日志很可能使用 NFS（Network File System），例如 AWS 的 EFS。这种 NFS 一动都可以动态的控制 IO 最大承载，但是服务的增长是很难预估完美的，并且高并发业务流量基本都是一瞬间到达，仅通过 IO 定时采集很难评估到真正的流量尖峰（例如 IO 定时采集是 5s 一次，但是在某一秒内突然到达很多流量，导致进程内大多线程阻塞，这之后采集 IO 看到 IO 压力貌似不大的样子）。并且，由于线程的阻塞，导致可能我们看到的 CPU 占用貌似也不高的样子。所以，外部定时采集指标，很难真正定位到日志流量问题。
然后我们考虑进程自己监控，暴露接口给外部监控定时检查，例如 K8s 的 pod 健康检查等等。在进程的日志写入压力过大的时候，新扩容一个实例；启动完成后，在注册中心将这个日志压力大的进程的状态设置为暂时下线（例如 Eureka 置为 OUT_OF_SERVICE，Nacos 置为 PAUSED），让流量转发到其他实例。待日志压力小之后，再修改状态为 UP，继续服务。
Log4j2 对于每一个 AsyncLogger 配置，都会创建一个独立的 RingBuffer，例如下面的 Log4j2 配置：
<!--省略了除了 loggers 以外的其他配置--> <loggers> <!--default logger --> <Asyncroot level="info" includeLocation="true"> <appender-ref ref="console"/> </Asyncroot> <AsyncLogger name="RocketmqClient" level="error" additivity="false" includeLocation="true"> <appender-ref ref="console"/> </AsyncLogger> <AsyncLogger name="com.alibaba.druid.pool.DruidDataSourceStatLoggerImpl" level="error" additivity="false" includeLocation="true"> <appender-ref ref="console"/> </AsyncLogger> <AsyncLogger name="org.mybatis" level="error" additivity="false" includeLocation="true"> <appender-ref ref="console"/> </AsyncLogger> </loggers>
这个配置包含 4 个 AsyncLogger，对于每个 AsyncLogger 都会创建一个 RingBuffer。Log4j2 也考虑到了监控 AsyncLogger 这种情况，所以将 AsyncLogger 的监控暴露成为一个 MBean（JMX Managed Bean）。
相关源码如下：
private static void registerLoggerConfigs(final LoggerContext ctx, final MBeanServer mbs, final Executor executor) throws InstanceAlreadyExistsException, MBeanRegistrationException, NotCompliantMBeanException { //获取 log4j2.xml 配置中的 loggers 标签下的所有配置值 final Map<String, LoggerConfig> map = ctx.getConfiguration().getLoggers(); //遍历每个 key，其实就是 logger 的 name for (final String name : map.keySet()) { final LoggerConfig cfg = map.get(name); final LoggerConfigAdmin mbean = new LoggerConfigAdmin(ctx, cfg); //对于每个 logger 注册一个 LoggerConfigAdmin register(mbs, mbean, mbean.getObjectName()); //如果是异步日志配置，则注册一个 RingBufferAdmin if (cfg instanceof AsyncLoggerConfig) { final AsyncLoggerConfig async = (AsyncLoggerConfig) cfg; final RingBufferAdmin rbmbean = async.createRingBufferAdmin(ctx.getName()); register(mbs, rbmbean, rbmbean.getObjectName()); } } }
创建的 MBean 的类源码：RingBufferAdmin.java
public class RingBufferAdmin implements RingBufferAdminMBean { private final RingBuffer<?> ringBuffer; private final ObjectName objectName; //... 省略其他我们不关心的代码 public static final String DOMAIN = "org.apache.logging.log4j2"; String PATTERN_ASYNC_LOGGER_CONFIG = DOMAIN + ":type=%s,component=Loggers,name=%s,subtype=RingBuffer"; //创建 RingBufferAdmin，名称格式符合 Mbean 的名称格式 public static RingBufferAdmin forAsyncLoggerConfig(final RingBuffer<?> ringBuffer, final String contextName, final String configName) { final String ctxName = Server.escape(contextName); //对于 RootLogger，这里 cfgName 为空字符串 final String cfgName = Server.escape(configName); final String name = String.format(PATTERN_ASYNC_LOGGER_CONFIG, ctxName, cfgName); return new RingBufferAdmin(ringBuffer, name); } //获取 RingBuffer 的大小 @Override public long getBufferSize() { return ringBuffer == null ? 0 : ringBuffer.getBufferSize(); } //获取 RingBuffer 剩余的大小 @Override public long getRemainingCapacity() { return ringBuffer == null ? 0 : ringBuffer.remainingCapacity(); } public ObjectName getObjectName() { return objectName; } }
我们可以通过 JConsole 查看对应的 MBean：
其中 2f0e140b 为 LoggerContext 的 name。
我们的微服务项目中使用了 spring boot，并且集成了 prometheus。我们可以通过将 Log4j2 RingBuffer 大小作为指标暴露到 prometheus 中，通过如下代码：
import io.micrometer.core.instrument.Gauge; import io.micrometer.prometheus.PrometheusMeterRegistry; import lombok.extern.log4j.Log4j2; import org.apache.commons.lang3.StringUtils; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.jmx.RingBufferAdminMBean; import org.springframework.beans.factory.ObjectProvider; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.actuate.autoconfigure.metrics.export.ConditionalOnEnabledMetricsExport; import org.springframework.context.annotation.Configuration; import org.springframework.context.event.ContextRefreshedEvent; import org.springframework.context.event.EventListener; import javax.annotation.PostConstruct; import javax.management.ObjectName; import java.lang.management.ManagementFactory; @Log4j2 @Configuration(proxyBeanMethods = false) //需要在引入了 prometheus 并且 actuator 暴露了 prometheus 端口的情况下才加载 @ConditionalOnEnabledMetricsExport("prometheus") public class Log4j2Configuration { @Autowired private ObjectProvider<PrometheusMeterRegistry> meterRegistry; //只初始化一次 private volatile boolean isInitialized = false; //需要在 ApplicationContext 刷新之后进行注册 //在加载 ApplicationContext 之前，日志配置就已经初始化好了 //但是 prometheus 的相关 Bean 加载比较复杂，并且随着版本更迭改动比较多，所以就直接偷懒，在整个 ApplicationContext 刷新之后再注册 // ApplicationContext 可能 refresh 多次，例如调用 /actuator/refresh，还有就是多 ApplicationContext 的场景 // 这里为了简单，通过一个简单的 isInitialized 判断是否是第一次初始化，保证只初始化一次 @EventListener(ContextRefreshedEvent.class) public synchronized void init() { if (!isInitialized) { //通过 LogManager 获取 LoggerContext，从而获取配置 LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false); org.apache.logging.log4j.core.config.Configuration configuration = loggerContext.getConfiguration(); //获取 LoggerContext 的名称，因为 Mbean 的名称包含这个 String ctxName = loggerContext.getName(); configuration.getLoggers().keySet().forEach(k -> { try { //针对 RootLogger，它的 cfgName 是空字符串，为了显示好看，我们在 prometheus 中将它命名为 root String cfgName = StringUtils.isBlank(k) ? "" : k; String gaugeName = StringUtils.isBlank(k) ? "root" : k; Gauge.builder(gaugeName + "_logger_ring_buffer_remaining_capacity", () -> { try { return (Number) ManagementFactory.getPlatformMBeanServer() .getAttribute(new ObjectName( //按照 Log4j2 源码中的命名方式组装名称 String.format(RingBufferAdminMBean.PATTERN_ASYNC_LOGGER_CONFIG, ctxName, cfgName) //获取剩余大小，注意这个是严格区分大小写的 ), "RemainingCapacity"); } catch (Exception e) { log.error("get {} ring buffer remaining size error", k, e); } return -1; }).register(meterRegistry.getIfAvailable()); } catch (Exception e) { log.error("Log4j2Configuration-init error: {}", e.getMessage(), e); } }); isInitialized = true; } } }
增加这个代码之后，请求 /actuator/prometheus 之后，可以看到对应的返回：
//省略其他的 # HELP root_logger_ring_buffer_remaining_capacity # TYPE root_logger_ring_buffer_remaining_capacity gauge root_logger_ring_buffer_remaining_capacity 262144.0 # HELP org_mybatis_logger_ring_buffer_remaining_capacity # TYPE org_mybatis_logger_ring_buffer_remaining_capacity gauge org_mybatis_logger_ring_buffer_remaining_capacity 262144.0 # HELP com_alibaba_druid_pool_DruidDataSourceStatLoggerImpl_logger_ring_buffer_remaining_capacity # TYPE com_alibaba_druid_pool_DruidDataSourceStatLoggerImpl_logger_ring_buffer_remaining_capacity gauge com_alibaba_druid_pool_DruidDataSourceStatLoggerImpl_logger_ring_buffer_remaining_capacity 262144.0 # HELP RocketmqClient_logger_ring_buffer_remaining_capacity # TYPE RocketmqClient_logger_ring_buffer_remaining_capacity gauge RocketmqClient_logger_ring_buffer_remaining_capacity 262144.0
这样，当这个值为 0 持续一段时间后（就代表 RingBuffer 满了，日志生成速度已经远大于消费写入 Appender 的速度了），我们就认为这个应用日志负载过高了。
