重构案例实战（下）：日志系统重构——从同步阻塞到异步管道+结构化日志

好，咱们接着聊日志系统重构的下半场。上一章我们把问题拆清楚了——同步阻塞、日志格式混乱、排查问题全靠肉眼 grep。这一章，我直接带你动手改代码。

说实话，我见过太多团队在日志这块「凑合着用」。等到线上出故障，才发现日志根本没法看。嗯，这次重构的核心目标就两个：不阻塞业务线程，以及日志能直接被机器读懂。

重构目标：我们要改成什么样？

先画个蓝图。我个人习惯在动手前先想清楚终点长什么样。这次的目标架构是这样的：

说白了，就是让业务线程只管扔日志事件，不碰 IO。日志的格式化、写入全部交给后台线程去干。你想想看，这就像餐厅里客人点完菜就走，后厨慢慢做——客人不用等。

第一步：定义结构化日志事件

老代码里日志是字符串拼接：logger.info("用户" + userId + "下单成功")。这种写法有两个问题：一是字符串拼接本身有性能开销，二是没法做结构化查询。

我建议改成事件对象。每个日志就是一个结构体，字段清清楚楚：

// 结构化日志事件
public class LogEvent {
    private long timestamp;      // 时间戳（纳秒级）
    private String traceId;      // 链路追踪ID
    private String level;        // 日志级别
    private String module;       // 模块名
    private String action;       // 操作名
    private Map<String, Object> fields;  // 业务字段
    private Throwable error;     // 异常信息（可选）

    // 构造方法、getter/setter 略
}

这里有个细节：fields 用 Map 而不是固定字段。为什么？因为不同业务场景需要的字段不一样。订单日志要订单号、金额；用户日志要用户ID、操作类型。用 Map 最灵活。

第二步：无锁队列——核心中的核心

同步阻塞的根因是什么？是业务线程直接调了 IO 写入。要解耦，就得引入一个缓冲区。这个缓冲区不能有锁——有锁就意味着可能阻塞。

我选的是 Disruptor 的 RingBuffer。它用数组实现，通过 CAS 操作控制生产者和消费者的游标，完全无锁。你想想看，在高并发下，锁竞争是性能杀手。Disruptor 的设计思路就是「用空间换时间」。

// 初始化 Disruptor
Disruptor<LogEvent> disruptor = new Disruptor<>(
    LogEvent::new,          // 事件工厂
    1024 * 64,              // RingBuffer 大小（必须是2的幂）
    Executors.defaultThreadFactory(),
    ProducerType.MULTI,     // 多生产者
    new BlockingWaitStrategy() // 等待策略
);

// 注册消费者
disruptor.handleEventsWith(new LogEventHandler());
disruptor.start();

// 生产者发布事件
RingBuffer<LogEvent> ringBuffer = disruptor.getRingBuffer();
long sequence = ringBuffer.next();
try {
    LogEvent event = ringBuffer.get(sequence);
    event.setTimestamp(System.nanoTime());
    event.setTraceId(traceId);
    event.setLevel("INFO");
    event.setAction("order.create");
    event.getFields().put("orderId", orderId);
    event.getFields().put("amount", amount);
} finally {
    ringBuffer.publish(sequence);
}

注意看，业务线程拿到 sequence 后，直接往 RingBuffer 里写数据，然后 publish。整个过程没有锁，没有 IO。就算日志线程处理不过来，RingBuffer 满了，业务线程也只是自旋等待——不会阻塞太久。

第三步：消费者线程——批量写入与格式化

消费者这边，我做了两件事：批量写入和 JSON 格式化。

批量写入很好理解——攒够一批日志再写文件，减少 IO 次数。Disruptor 默认就是批量消费的，你只需要在事件处理器里处理 List 就行。

public class LogEventHandler implements EventHandler<LogEvent> {
    private static final int BATCH_SIZE = 100;
    private final List<LogEvent> buffer = new ArrayList<>(BATCH_SIZE);

    @Override
    public void onEvent(LogEvent event, long sequence, boolean endOfBatch) {
        buffer.add(event);
        if (buffer.size() >= BATCH_SIZE || endOfBatch) {
            flush();
        }
    }

    private void flush() {
        // 批量写入文件
        try (FileWriter writer = new FileWriter("logs/app.log", true)) {
            for (LogEvent event : buffer) {
                writer.write(toJson(event));
                writer.write('\n');
            }
            writer.flush();
        } catch (IOException e) {
            // 这里不能再打日志了，否则死循环
            System.err.println("日志写入失败: " + e.getMessage());
        }
        buffer.clear();
    }

    private String toJson(LogEvent event) {
        // 用 Jackson 或 Gson 序列化
        return JsonUtil.toJson(event);
    }
}

这里有个坑：flush 方法里如果日志写入失败，千万别再调日志框架打日志——那会形成死循环。我一般直接写 stderr 或者发告警。

第四步：结构化日志的威力

改完以后，日志文件里每行都是一个 JSON：

{"timestamp":1723456789012,"traceId":"abc123","level":"INFO","module":"order","action":"create","fields":{"orderId":"ORD20241001","amount":99.9}}
{"timestamp":1723456789015,"traceId":"abc123","level":"WARN","module":"payment","action":"timeout","fields":{"orderId":"ORD20241001","paymentId":"PAY20241001"}}

你想想看，这种格式能干什么？

• 按 traceId 聚合：一条请求的所有日志，一秒内就能拎出来
• 按 level 过滤：只看 ERROR 级别的日志
• 按 action 统计：某个接口的调用次数、耗时分布
• 接入 ELK：直接扔到 Elasticsearch 里，Kibana 上做可视化

我记得有一次线上出问题，用户反馈下单失败。我用 traceId 一搜，发现日志里 payment 模块报了超时，但 order 模块没处理这个异常。5 分钟定位到问题。要是以前那种字符串拼接的日志，光 grep 就得半小时。

性能对比：重构前后

我在压测环境里跑了一组数据，大家感受一下差距：

业务线程的 QPS 提升了 7 倍，P99 延迟从 85ms 降到了 3ms。说白了，日志不再是瓶颈了。

重构后的架构总览

最后，我用一张图总结一下整个日志系统的数据流：

整个链路清晰了：业务代码 → 日志门面 → 无锁队列 → 消费者 → 输出。每个环节各司其职，没有阻塞点。

好了，日志系统重构的实战部分就到这里。核心思路就是一句话：别让业务线程干脏活累活。把 IO、格式化这些事交给后台线程，用无锁队列做缓冲，用结构化格式做输出。这套方案我在多个项目里验证过，效果都很好。