异步日志并不等于没有开销。当磁盘、容器日志管道或采集端变慢时,有限队列会在丢日志与阻塞业务线程之间做出选择。本文从 Logback 队列机制、线程栈特征、监控指标和生产配置入手,给出一条可落地的排查路径。

问题背景

一次常见但容易误判的线上现象是:接口 P99 延迟突然升高,CPU、堆内存、数据库连接池都没有明显异常,重启实例后又暂时恢复。应用日志仍在输出,因此排查者很容易把日志系统排除在外。

真正的问题可能恰好出在日志链路。业务线程生成日志后,先把事件放入内存队列,再由后台线程写入文件或标准输出。如果磁盘延迟升高、文件系统空间不足、容器运行时读取 stdout 变慢,或者日志采集代理发生背压,消费速度就会低于生产速度。有限队列被填满后,异步日志只能选择阻塞调用线程或丢弃事件。

这类故障的关键不是“有没有使用异步日志”,而是:队列满时系统采取什么策略,以及这个状态能否被监控到。

AsyncAppender 的工作方式

Logback 的 AsyncAppender 本身不负责落盘。它接收 ILoggingEvent,放入阻塞队列,再由工作线程转交给内部的文件、控制台等 Appender。调用链可以简化为:

业务线程 -> AsyncAppender 队列 -> 后台工作线程 -> FileAppender/stdout -> 磁盘或采集端

队列隔离了短时间的写入抖动,却不能消除下游吞吐上限。假设高峰期每秒产生 8000 条日志,下游只能处理 5000 条,那么队列再大也只是在推迟队列耗尽的时间。

neverBlock=false 时,队列无法接收新事件后,业务线程可能等待可用位置,日志延迟由此变成接口延迟。neverBlock=true 时,调用线程不会等待,但队列已满时日志会被丢弃。两种策略都不是无条件正确:普通诊断日志通常更适合限量丢弃,而审计、账务等不能丢失的数据不应只依赖普通日志通道。

下面是一份偏向“保护业务可用性”的 Logback 配置。它适用于使用 Logback 的常规 Java 服务;具体滚动策略仍应结合磁盘容量调整。

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/application.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>logs/application.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxFileSize>200MB</maxFileSize>
            <maxHistory>7</maxHistory>
            <totalSizeCap>10GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
            <pattern>%d{ISO8601} %-5level [%thread] %logger{36} traceId=%X{traceId} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <queueSize>8192</queueSize>
        <discardingThreshold>1024</discardingThreshold>
        <neverBlock>true</neverBlock>
        <includeCallerData>false</includeCallerData>
        <appender-ref ref="FILE"/>
    </appender>

    <root level="INFO">
        <appender-ref ref="ASYNC_FILE"/>
    </root>
</configuration>

这里明确选择了队列满时不阻塞业务线程,并允许在剩余容量较低时优先丢弃低级别事件。队列大小不是越大越好:每个事件都持有消息、参数、MDC 等对象,过大的队列会增加内存占用,也会让故障恢复后出现长时间追赶。includeCallerData=false 则避免为每条日志提取调用位置带来的额外开销。

给日志队列加上可观测性

只监控日志文件增长速度不够,因为它看不到队列是否正在积压。使用 Spring Boot 3、Micrometer 和 Logback 时,可以把根 Logger 上的异步队列暴露为 Gauge:

package com.example.observability;

import ch.qos.logback.classic.AsyncAppender;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.core.Appender;
import io.micrometer.core.instrument.Gauge;
import io.micrometer.core.instrument.MeterRegistry;
import jakarta.annotation.PostConstruct;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Component
public class LogbackQueueMetrics {

    private final MeterRegistry registry;

    public LogbackQueueMetrics(MeterRegistry registry) {
        this.registry = registry;
    }

    @PostConstruct
    public void register() {
        Logger root = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
        Appender<?> appender = root.getAppender("ASYNC_FILE");
        if (!(appender instanceof AsyncAppender async)) {
            return;
        }

        Gauge.builder("logback.async.queue.elements", async,
                        AsyncAppender::getNumberOfElementsInQueue)
                .description("Events waiting in the Logback async queue")
                .register(registry);

        Gauge.builder("logback.async.queue.remaining", async,
                        AsyncAppender::getRemainingCapacity)
                .description("Remaining capacity of the Logback async queue")
                .register(registry);
    }
}

这段代码假设 ASYNC_FILE 直接挂在根 Logger 上。若项目通过多个 Logger 或复合 Appender 组织日志,应按实际结构查找,不能静默地把“没有注册指标”当成队列为空。告警也不应只看瞬时值:剩余容量持续偏低、队列元素持续上升,才更能说明消费端已经跟不上。

生产环境的定位顺序

首先抓取多份线程栈。如果大量请求线程停在 AsyncAppenderBaseBlockingQueue.putArrayBlockingQueue 或其条件等待附近,日志阻塞就有了直接证据。单份线程栈可能只捕获瞬时等待,间隔数秒连续采样更可靠。

其次检查真正的下游。写文件时关注磁盘延迟、利用率、剩余空间和 inode,而不只是磁盘容量;写标准输出时,还要检查容器运行时和日志采集代理。应用看到的 stdout 也是一条有容量限制的管道,并不天然比文件可靠。

再次对齐时间线:比较接口延迟、日志队列深度、每秒日志量、磁盘写延迟以及采集端重试。若队列先增长,随后接口延迟升高,且线程栈出现入队等待,因果关系通常已经比较清楚。

最后定位日志突增来源。常见原因包括把循环内日志提升到 INFO、打印完整请求响应、异常重试时每次都输出堆栈,以及某个高频告警没有限流。修复下游只是恢复服务,控制无价值的日志量才是在消除诱因。

常见坑

第一,盲目扩大队列。大队列可以吸收短暂尖峰,但面对持续吞吐差额只会延后故障,并占用更多堆内存。应根据正常峰值、可接受缓冲时间和单条事件大小估算,而不是直接填一个很大的数字。

第二,把 neverBlock=true 当成完整方案。它保护了请求线程,却可能让关键故障现场消失。错误日志需要单独监控;真正要求可靠交付的审计事件,应写入数据库、消息系统或事务发件箱,而不是寄希望于日志文件。

第三,参数化日志不等于没有计算开销。下面的调用即使 DEBUG 被关闭,也会先执行序列化:

log.debug("order snapshot={}", expensiveSerialize(order));

对于昂贵计算,应显式判断:

if (log.isDebugEnabled()) {
    log.debug("order snapshot={}", expensiveSerialize(order));
}

第四,只保存平均延迟。日志背压通常先影响部分高日志量请求,平均值可能变化不大,P95、P99 和线程池活跃数更容易暴露问题。

实践建议

生产配置应明确记录队列容量、丢弃阈值和满队列策略,并通过压测验证,而不是依赖组件默认值。对登录、批处理、异常重试等日志密集路径单独施压,同时模拟慢磁盘或暂停采集端,观察请求延迟与日志损失。

日志内容也应有预算意识:稳定的事件名称、必要的业务标识和简短错误上下文通常比整个对象快照更有价值。对重复异常做采样或限流,但保留累计次数指标,使“少打印”不会变成“看不见”。

总结

异步日志只是用队列把写入成本从当前调用暂时移开,并没有让 I/O 成本消失。定位这类故障,需要同时观察业务线程、异步队列和最终输出端。队列满时阻塞还是丢弃,应由日志的重要程度决定;不能丢失的业务事实,则应离开普通日志通道。把队列深度纳入监控、在压测中制造下游变慢,并控制高频日志量,才能避免日志系统在故障时反过来拖住服务。

最后修改:2026 年 08 月 24 日
如果觉得我的文章对你有用,请随意赞赏