怎样监管 Log4j2 多线程日志碰到载入短板

在以前的一篇文章中(一次力透纸背的 Log4j2 多线程日志輸出堵塞难题的精准定位)，大家深入分析了一个經典的 Log4j2 多线程日志堵塞难题的精准定位，关键缘故或是日志文档载入慢了。而且较为深层次的剖析了 Log4j2 多线程日志的基本原理，最终得出了一些解决方法。

新的难题 – 怎样更强的解决这类状况？

以前明确提出的解决方法只是是对于以前精准定位的难题的提升，可是伴随着市场拓展，日志量毫无疑问会大量，很多的日志很有可能造成载入日志变成新的特性短板。针对这类状况，大家必须 监管。

最先想起的是过程外界采集系统指标值监管：如今服务项目都倡导使用云服务器，并完成云原生服务项目。针对云服务器，储存日志很可能应用 NFS（Network File System），比如 AWS 的 EFS。这类 NFS 一动都能够动态性的操纵 IO 较大 安装，可是服务项目的提高是难以预计极致的，而且分布式系统业务流程总流量基本上全是一瞬间抵达，仅根据 IO 按时收集难以评定到真真正正的总流量顶峰（比如 IO 按时收集是 5s 一次，可是在某一秒内忽然抵达许多总流量，造成过程内大线程同步堵塞，这以后收集 IO 见到 IO 工作压力好像并不大的模样）。而且，因为进程的堵塞，造成很有可能大家见到的 CPU 占有好像都不高的模样。因此，外界按时收集指标值，难以真真正正精准定位到日志总流量难题。

随后大家考虑到过程自身监管，曝露插口给外界监管按时查验，比如 K8s 的 pod 健康体检这些。在过程的日志载入工作压力过大的情况下，新扩充一个案例；运行进行后，在认证中心将这一日志压力太大的过程的情况设定为临时退出（比如 Eureka 置为 OUT_OF_SERVICE，Nacos 置为 PAUSED），让总流量分享到别的案例。待日志工作压力小以后，再改动情况为 UP，再次服务项目。

那麼怎样完成这类监管呢？

监管 Log4j2 多线程日志的关键 – 监管 RingBuffer

依据以前大家剖析 Log4j2 多线程日志的基本原理，我们知道其关键是 RingBuffer 这一算法设计做为缓存文件。我们可以监管其剩下尺寸的转变来分辨当今日志工作压力。那麼怎能取得呢？

Log4j2 多线程日志与 RingBuffer 的关联

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）。

有关源代码以下：

Server.java

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();
    //解析xml每一个 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 尺寸

大家的微服务中应用了 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 的速率了），大家就觉得这一运用日志负荷过高了。