异步日志与结果回执：从P999飙升到稳定降级的接口性能优化实践

接到一个接口性能优化任务时，我一度以为问题出在数据库或者序列化层。可实测结果出来，最大头竟然是日志：一次请求要同步写两条审计日志，每条日志都要完成序列化、落盘、再往日志采集端做一次 HTTP 推送，单次耗时能到 40ms。高并发下一放大，核心接口的 P999 直接从 120ms 飘到了 560ms。那时候脑子里冒出来的方案就是“异步记录日志+获取异步处理结果”——日志写入全部挪到异步线程池，主线程不再等它；但业务方确实还有后续动作依赖这条日志的处理结果，不能简单“发完就忘”。这个组合听起来有点矛盾，但在真实项目里太常见了：前半句解决“别拖慢我”，后半句解决“但我还得知道它到底成没成”。

这篇文章我会从一次真实的改造经历出发，把为什么需要这个组合、线程池和队列怎么配、结果应该怎么拿、以及上线后最容易踩的坑一次讲清楚。适合正在做接口性能优化、想把日志或事件上报改成异步链路、又不想丢掉执行结果的开发者参考。

1. 一次接口变慢牵出的组合问题：异步写日志与回执等待

1.1 从耗时拆解开始：日志同步写是如何拖垮主链路的

优化接口不能靠猜。我先在核心服务里加了一圈耗时打点，把一次请求拆成参数解析、业务查询、数据库写入、日志写出、响应组装五个阶段。结果业务逻辑只花了 30ms，日志写出反而平均 35ms，有时候能到 80ms。为什么日志会这么慢？拆开看，一条日志从产生到真正落库，至少要经过：对象序列化成 JSON、写本地文件或直接发远端采集接口、采集端再异步批量刷盘。如果中间还接了日志平台的 HTTP API，那一次网络往返就是 10ms 起步。

高并发下，这个问题会被放大成明显的 RT 毛刺。同步写日志时，每个请求线程都在抢占文件锁或者连接池，线程一多，等待时间叠加，最终表现为接口整体变慢。更难受的是，日志系统一旦抖动，业务接口也跟着失败——这属于典型的“旁路故障拖垮主路”。

1.2 为什么“发完就忘”的日志，业务却非要拿到结果

很多人一听到异步日志，下意识就觉得应该是 fire-and-forget：提交线程池完事，主线程继续跑。但真实业务里，日志往往不是写完就结束的“纯日志”，它还承担着审计、告警、状态回写这类“副作用”。

我这次的项目就是这样：系统每处理一个订单事件，都要先记录一条风控审计日志，日志落库后返回一个日志ID，这个ID需要回填到订单状态表里，方便后续对账和排查；如果日志写入失败，还要触发一条告警通知到值班群。换句话讲，日志记录的动作是异步的，但它的处理结果必须要能回到业务侧。如果做成丢进线程池就不管，那日志ID永远是空，告警也永远不会触发，出了问题只能靠人工翻日志，等于把异步改造做成了一次“降级”。

1.3 先分清需求边界：结果到底是给谁用的

异步日志是否需要“拿到结果”，取决于日志之后还接了什么。这里我总结了三类情况，你可以对号入座：

我这次属于第二种和第三种的混合：主流程不因为日志失败而回滚，但状态回写和告警仍然要做。所以最终采用“异步执行 + 回调通知 + 监控兜底”的方案，而不是在主线程里用 Future.get 硬等。这个选择的代价和收益，在第 3 部分会展开。

2. 自建异步日志服务时，线程池与队列的正确姿势

2.1 三条路线：自建线程池、内存队列、日志框架自带的异步能力

做异步日志，我最开始面临三个选择，这里直接拿表格对比一下：

日志框架自带的异步 Appender 最省事，比如 Logback 的 AsyncAppender，内部用有界队列承接日志事件，业务线程把日志扔进队列就走了。它对“获取异步处理结果”基本无能为力，因为日志框架的设计目标就是“写进去就跟你没关系了”。我这次既需要异步写日志，又需要把日志ID回传，所以选了自建线程池。

2.2 线程池参数与拒绝策略：日志场景不能照搬默认配置

线程池参数不能拍脑袋。日志任务属于 IO 密集型任务，除了写本地文件，还要做网络请求发送到采集端，所以线程数可以比 CPU 核数多。我这次的配置逻辑是：核心线程数 8，最大线程数 16，队列用有界队列，容量 4096；线程名统一加 async-log 前缀，方便排查线程栈和死锁。

public class LogRecorder { private final ExecutorService executor = new ThreadPoolExecutor( 8, 16, 60L, TimeUnit.SECONDS, new ArrayBlockingQueue<>(4096), r -> { Thread t = new Thread(r); t.setName("async-log-" + t.getId()); t.setDaemon(true); return t; }, new RejectedExecutionHandler() { @Override public void rejectedExecution(Runnable r, ThreadPoolExecutor e) { // 异步日志宁可降级，也不能抛异常回主线程 LogMetrics.incrementRejectedCount(); if (r instanceof LogTask) { fallbackLogger.log(((LogTask) r).getEvent()); } } } ); }

拒绝策略是这里最值得强调的点。默认的 AbortPolicy 会直接抛 RejectedExecutionException，业务线程调用日志方法时万一线程池满了，接口直接 500，这是绝对不能接受的。DiscardPolicy 又太“静默”，日志直接没了还不自知。我最后用的是自定义策略：拒绝时计数，同时把最关键的业务日志降级为同步写。这样既保证业务接口不炸，又不会完全丢数据。

注意：CallerRunsPolicy 看起来两全其美，但它在线程池满的时候会把任务丢回调用线程执行。高峰流量下，这等于日志从异步悄悄变回了同步，RT 毛刺会比现在更严重。用到它之前一定要想清楚这个后果。

2.3 没有监控的异步日志就是黑洞

异步日志最大的风险是“静默失败”。日志提交成功不代表写入成功，所以必须配上指标。我在 LogRecorder 里维护了几个计数器：提交总数、执行成功数、执行失败数、拒绝数，以及当前队列长度。上线后通过定时任务每 30 秒打印一次到独立日志文件，同时在监控大盘上展示。这样一旦日志丢失率超过阈值，或者队列积压持续增长，我能在几分钟内发现，而不是等到业务方反馈“日志怎么查不到”才开始排查。

3. 靠Future和回调拿结果：最稳的做法不是“等”

3.1 Future.get 为什么容易写坏：从超时到线程泄漏

自建线程池之后，很多人会顺手把任务提交成 Future，然后在业务里 Future.get()。我最初也是这么写的：

Future<LogResult> future = logRecorder.submit(event); LogResult result = future.get(3, TimeUnit.SECONDS);

这个写法最明显的问题是：当接口有大量请求同时进来时，业务线程为了等日志结果，集体阻塞在 get 上。表面上是异步，实际上又把日志写回同步，线程池的资源优势荡然无存。有一个隐藏问题是 get 超时后，任务线程仍在后台执行，如果日志平台刚好很慢，超时线程会越来越多，最终看到的现象就是 tomcat 线程耗尽，接口大面积卡顿。

更深层的风险是：get 结果只返回成功或失败，但要判断“日志到底有没有落库”，靠一个返回值是不够的。日志落库是个“最终一致”的过程，这种短暂的等待对业务正确性帮助有限，反而把接口拖住。所以除非你的超时容忍度特别低，我一般不建议在主线程里等 Future。

3.2 CompletableFuture 回调：把“拿结果”改成“结果来了再干活”

我更推荐的方式是 CompletableFuture 回调。业务方不阻塞等待，而是注册一个回调函数，等异步日志任务真正跑完，再触发状态回写、告警或者指标上报。核心代码如下：

public void recordAndNotify(String orderId, LogEvent event) { CompletableFuture<LogResult> future = CompletableFuture.supplyAsync(() -> persist(event), logExecutor); future.whenComplete((result, error) -> { if (error != null) { // 异步任务本身抛异常，走告警链路，不抛回主线程 alertService.notify(orderId, error); LogMetrics.incrementFailedCount(); return; } // 日志入库成功，用返回的日志ID更新业务状态 orderStatusService.updateLogId(orderId, result.getLogId()); LogMetrics.incrementSuccessCount(); }); }

这个写法和 Future.get 的本质区别是：发起方只负责提交任务，后续动作全部交给回调；主线程可以立刻返回，继续处理下一个请求。日志结果不是“拿”回来的，而是“等它送到”的。用生活类比就是：你去餐厅点餐，不用站在取餐口等着，拿个叫号器，餐好了震动通知你再去取。Future.get 是死站在取餐口盯出餐口，CompletableFuture 回调是拿个叫号器去旁边刷手机。

不过也要注意，回调线程跑在日志线程池里，如果回调里有耗时的网络请求，它会反过来占用日志线程。所以回调里我只做状态回写和指标上报这种轻操作，不会在回调里再去请求其他外部服务。

3.3 状态轮询表与最终一致：当结果可能要等几秒

还有一种场景，日志结果可能要等好几秒才出来——例如日志采集端是每 5 秒批量刷盘一次，或者日志服务本身做了异步批量写入。这种情况下，无论 Future 还是回调都不合适：Future 等不了那么久，回调存在但状态还没最终落库，返回的结果可能是不准确的。

我的做法是引入一张“异步任务结果表”，把日志任务状态建模成 processing、done、failed 三态。业务侧拿到 taskId 后，可以轮询这张表，或者等任务完成后由回调把状态置为 done。表结构大致是：

CREATE TABLE async_task_result ( task_id VARCHAR(64) PRIMARY KEY, biz_id VARCHAR(64) NOT NULL, status TINYINT NOT NULL COMMENT '0:processing 1:done 2:failed', result_data JSON NULL, error_msg VARCHAR(512) NULL, create_time DATETIME NOT NULL, update_time DATETIME NOT NULL );

这是典型的最终一致设计：业务不需要实时拿到结果，它只需要保证“过一段时间后能查到结果，并且结果是对的”。在日志这类旁路系统上，最终一致完全够用，而且比强行同步的效果好得多。

3.4 决定用哪种方式之前，先回答三个问题

很多人纠结于技术选型，其实答案早就在需求里。每次遇到“异步后怎么获取结果”，我都会先问自己三个问题：

1. 这个结果拿不到，主流程能不能继续？如果不能，那就别做异步，老老实实同步写。
2. 主流程能容忍的最大等待时间是多少？如果只有几十毫秒，考虑回调；如果能等几秒，考虑轮询表。
3. 结果最终用来干什么？用来阻断、用来回写，还是只用来告警和统计？阻断必须谨慎，回写走回调或轮询，告警统计用指标就能覆盖。

把这三个问题回答完，方案基本就定了，不需要纠结 API 写法。

4. 我踩过的几个真实坑：上下文、乱序、重试一个都不少

4.1 ThreadLocal 里的 TraceId 不会自动跟到异步线程

异步改造上线第一天，我就被同事叫去看日志：为什么同一笔订单在日志平台里查不到完整的调用链？排查后发现，问题出在 TraceId。原来主线程通过 ThreadLocal 和 MDC 放进去的 TraceId，提交到线程池后，异步线程根本读不到。于是这条日志在日志平台里变成了一个“孤儿日志”，既排不进调用链，也没法跟请求关联。

解决方案不复杂：提交任务前，把当前线程的 MDC 内容快照成一份上下文对象，提交时一起传给线程池。任务执行前恢复上下文，执行完清理干净。这样既保证 TraceId 能串起来，也避免异步线程之间的上下文互相污染。可以用一段伪代码来表达：

public <T> Future<T> submitWithContext(Callable<T> task) { Map<String, String> context = MDC.getCopyOfContextMap(); return executor.submit(() -> { MDC.setContextMap(context); try { return task.call(); } finally { MDC.clear(); } }); }

提示：这步看起来小，但不做的话，异步日志的排查价值直接减半。上线前一定要在测试环境用实际流量验证 TraceId 能跨线程串联。

4.2 并发下事件乱序：“先发生”的日志比“后发生”的晚落库

第二个坑出现在订单事件审计上。系统里同一个订单会先后产生“创建”“支付”“发货”三个事件，日志落库后要让视图层按事件顺序展示。但异步线程池是多线程并发消费，创建事件和支付事件可能被两个线程同时处理，支付事件先落库了，创建事件反而在后面。客户看到的订单时间线就成了“已支付 -> 已创建 -> 已发货”，审计上完全不可用。

要解决乱序，我做了两个动作：一是给每个日志事件打上业务时间戳，查询时统一按时间戳排序，这是兜底；二是对需要顺序保证的事件，按订单ID做 hash 取模，把同一个订单的事件路由到同一个线程。做法是在任务里加一个 routingKey，线程池内部用多个单线程队列来消费同 key 任务。代价是同一个订单的日志并发度下降了，但换来了顺序的确定性，对审计类需求来说是值得的。

4.3 任务失败重试：日志重复比丢失更难处理

日志写入失败后，第一反应是加重试。我加过，然后尝到了苦果：日志平台一次网络抖动，重试机制把同一批数据写了两遍，后面对账时发现记录数翻倍，查了半天才发现是重试造成的重复写入。

对于日志这类追加写的数据，重复比丢失更难处理，因为重复会污染统计和审计。所以我后来把所有日志任务都设计成带幂等键：每条日志生成一个全局唯一的 eventId，日志平台落库时把 eventId 作为唯一索引，重复提交直接忽略。对于必须重试的场景，我宁可选择“丢弃并计数”，也不做无脑重试，因为日志缺失可以通过监控发现，但数据重复很难靠人工清洗。

4.4 结果获取超时引发的事务回滚与最终不一致

最让我后怕的一个场景是：某个接口把异步日志的结果用 Future.get 等回来，再根据结果决定事务提交还是回滚。结果是某次日志平台整体变慢，Future.get 超时，业务接口抛了 TimeoutException，事务回滚了；但日志任务其实在后台延迟写入成功了。用户看到接口失败，重新下单，实际上一前一后写了两条订单记录，对账的时候数据完全对不上。

这个教训让我彻底明白：异步日志的结果，绝对不应该承担事务性主流程的成功失败判定。日志只是旁路，它该做的是记录和反馈，而不是反过来决定业务是不是成功。改造后，我把所有“根据日志结果决定业务成败”的逻辑全部删掉，日志失败只走告警和监控，不再影响主流程。

5. 效果验证：压测数据与上线确认清单

5.1 模拟压测的对比数据

我在一个模拟项目 X 上做了三组压测对比，线程池配置相同，接口逻辑相同，区别只在日志处理方式。结果如下：

数据很直观：真正纯异步回调的方案，P999 从 560ms 降到 145ms，吞吐量接近原来的 2.6 倍，而业务错误率降到了 0。Future.get 的方案虽然也有提升，但超时会导致错误率上升，本质上还是没有完全脱离“异步变同步”的问题。

要说明的是，这是我项目里的实测结果，不同项目的数据会因机器配置、日志平台性能、日志量大小而不同。但趋势是一致的：只有把主线程从等待中彻底解放出来，异步日志的收益才是完整的。

5.2 上线前逐条检查的清单

经历过这些坑之后，我列了一份异步日志上线的检查清单，每次接手类似改造都会对照走一遍：

清单里的每一条，都是用真实故障换来的。上线前哪怕漏掉一项，都可能在某次大促或日志平台抖动时爆出问题。

5.3 个人体会：先做减法，再做异步

回过头看这次改造，如果让我重新做一次，我会先做减法：把日志分类，哪些真的需要结果，哪些根本不需要结果。纯访问日志、调试日志，直接丢给日志框架的异步 Appender，谁都不需要等它。真正需要拿到结果的日志，我也不会让业务线程在接口里 get，而是用回调去更新状态和指标。异步化的本质是把耗时的旁路动作移出主链路，同时保留主链路对结果的感知能力，但感知的方式不一定是阻塞等待。

我再分享一个判断标准：如果你发现自己在异步线程里反复尝试获取结果、反复担心拿不到结果，那大概率是这个功能就不适合异步。要么你把结果的使用方式改成“最终一致 + 回调通知”，要么直接把它拉回同步，不要为了异步而异步。这个标准帮我避开了很多过度设计，也建议你在动手前先拿它卡一下自己的需求。