企业官网建设流程全解析

先说个结论：异步日志本身不是坑，把异步日志当成“写完就跟我没关系”才是坑。前段时间我维护的某订单系统就因为这个差点把日志系统整个丢掉——112 万条排查故障的关键日志全部积压在一个无人在读的内存队列里，消费者线程早就因为一条坏数据崩没了，存储侧却干干净净一条都没有。当时我手里只剩三行代码，硬是把这批数据从队列里掏了出来，写进了兜底文件。今天这篇就把 Serilog 异步配置逐行拆开讲清楚，顺便把 AsyncLocal 那两个最容易踩的陷阱标红，给和我一样在日志管道上翻过车的人做个参考。这篇东西不是什么理论课，就是一次真实事故的现场复盘加事后修复总结。

1. 先还原现场：一条日志是怎么“人间蒸发”的

1.1 事故的表象：日志在某个时间点集体失联

系统是某公司一个订单服务，.NET 8，日志组件一直是 Serilog。早期日志量不大，我图省事直接用同步方式写文件，接口慢也就慢了。后来日志要进检索系统，方便排查问题，才在中间加了一层异步队列：业务线程只负责把LogEvent塞进队列，后台消费者统一批量写检索系统。

出事那天下午，前端大面积告警，后端排查问题，习惯性先翻日志。打开检索系统发现日志库最后一条记录的时间戳停在 13:02:18，之后所有请求的日志集体失联。不是某一台机器坏了，而是整个服务的日志都断了。当时线上还在持续报错，我却找不到任何后端日志可以看，那种感觉就像握着方向盘踩刹车却没反应。

一开始我怀疑是检索系统的连接问题，测了网络、看了连接池，一切正常。然后看进程状态，进程还活着，但内存占用高得离谱，GC 一直在顶。我赶紧连上用 dotnet-dump 打了快照，再翻代码里队列的计数，才发现问题远比连接故障严重——那会儿内存队列里已经积压了 112 万条待写的日志事件。

1.2 真相：消费者线程没了，队列还在硬扛

为什么日志会停在 13:02:18？因为检索系统写入端在 13:02 左右收到有一条特殊数据，序列化时发生了异常。我当时写的消费者循环非常直白：while (true)读队列，逐条转成文档写入检索系统。这种写法最怕的就是“循环体内出现未捕获异常”。一条坏数据让异常直接炸穿整个消费者线程，线程死了，循环停了，但业务线程并不知道这件事，依然往队列里继续塞日志。

队列是无界的，写着写着就堆到了 112 万条。更麻烦的是，无界队列没有背压，内存越吃越多。业务接口还在跑，日志还在产生，但没有任何人消费。检索系统看到的自然就是最后一条日志之后，所有日志“蒸发”。

这里有个扎心的事实：异步日志引入的缓冲区，本质上是把“写不写得出去”的问题从调用线程转移到了一个后台执行者身上。后台执行者一旦挂了，缓冲区就成了黑洞。同步写日志虽然慢，但只要磁盘没挂，日志至少不会凭空少一段。

1.3 为什么“异步日志”这么容易翻车

异步写日志的本质，是把emit和write解耦。日志在调用线程上被创建，但真正写盘、写检索系统发生在另一个线程上。这个“解耦”带来了吞吐量，也带来了三个全新的故障点：

第一，生产者可能无限制地往队列里塞东西。如果没有容量上限或背压，消费者一挂，内存就会被日志堆满。第二，消费者可能因为单条坏数据而整体崩溃。日志事件是程序员写的，永远有意外值，而消费者循环往往只考虑了“正常路径”。第三，进程退出时如果没人负责任地把队列排空，积压的数据直接就没了。

我给当时的设计总结成三条铁律：生产者不能无限塞，消费者不能裸奔跑，停机必须排空缓冲。这三条看起来简单，但如果你没有踩过“日志集体失联”的坑，很容易觉得它们是废话。

2. Serilog 异步配置逐行扒皮：官方方案到底该怎么用

2.1 最容易被忽略的三个参数

Serilog 官方其实有现成的异步包装器，也就是WriteTo.Async(...)，它内部维护一个后台队列。很多人只知道“加了这个日志就变快了”，却不知道队列容量、队满策略这些参数才是决定日志会不会丢的关键。我把最重要的三个参数按优先级列一下，方便对号入座。

bufferSize是队列容量，默认 10000。它不是吞吐量，而是“积压能力”。假设你的系统峰值每秒产生 3000 条日志，消费者每秒只能处理 500 条，那么每秒积压 2500 条，默认容量 4 秒就满了。如果消费者刚好卡顿几十秒，队满之后就面临丢日志的抉择。

blockWhenFull默认是 true，意思是队满时调用线程阻塞等待，用牺牲响应速度来换取不丢事件。在 ASP.NET Core 的 Web 请求线程上，这意味着线程在日志上卡住，接口延迟会被拉高。如果设成 false，队满时不再阻塞，但会开始丢事件——这个“丢”的语义很多人不了解：不开droppingEvents选项时，默认会从队首丢最旧的事件来给新事件腾位置；开了droppingEvents之后才反过来，丢的是当前这条新事件。所以“丢”是必然的，只是丢谁的区别。

droppingEvents默认 false，配合blockWhenFull: false时才有实际意义。它决定队满后淘汰旧事件还是丢弃新事件。生产环境里，无论选哪一种，都意味着有日志凭空消失，所以正确做法不是纠结丢谁，而是把容量和消费者性能规划好，尽量别让队满发生。

2.2 从一行常用配置拆出背后的调度逻辑

我后来的日志配置长这样，先看代码，再逐行解释：

Log.Logger = new LoggerConfiguration() .MinimumLevel.Information() .Enrich.FromLogContext() .WriteTo.Async(a => { a.File("logs/order-.log", rollingInterval: RollingInterval.Day, retainedFileCountLimit: 30, shared: true, flushToDiskInterval: TimeSpan.FromSeconds(1)); }, bufferSize: 100_000, blockWhenFull: true) .WriteTo.Console() .CreateLogger();

MinimumLevel.Information()把调试日志挡在门口，避免日志量爆炸。Enrich.FromLogContext()表示让每个日志事件在创建时自动拍下LogContext里的属性快照，这点后面讲 AsyncLocal 陷阱时还会用到。WriteTo.Async(...)是核心，它把内部的 File sink 包装进后台队列，调用线程只做入队。bufferSize: 100_000是按“峰值速率 × 消费者最坏恢复时间”估算出来的容量。blockWhenFull: true是我最终的选择，因为对订单系统来说，接口慢一点可以接受，日志丢了没法接受。文件 sink 里的retainedFileCountLimit: 30是保留 30 个滚动文件，shared: true允许多个进程写同一个日志文件，flushToDiskInterval控制文件 sink 内部缓冲多久刷一次盘。

这里有一个很多人不知道的细节：File sink 本身是有写缓冲的，flushToDiskInterval设成一秒，意味着日志事件进入文件 sink 之后不一定立刻落盘。如果这时候进程被强制杀掉，最后这一秒的数据也可能丢。所以官方方案并不能做到“理论上不丢”，它只是把丢数据的窗口缩小了。

2.3 官方方案与自研 Channel：什么时候不该重复造轮子

WriteTo.Async(...)适合大部分常规场景，尤其是你的下游只是文件、数据库这类单消费者场景。它的队列和后台线程都是封装好的，参数也够用。但注意一个原则：不要用它去包装一个本身已经异步的 sink，比如已经有内部批处理机制的写库 sink，套两层队列只会让链路更复杂，还增加上下文丢失的可能。

我这次事故用的是自研 Channel，原因是我当时需要批量写检索系统、做失败重试和离线降级，这些官方 Async 包装器给不了。但自研的代价是，你需要自己保证消费者循环的健壮性、队列的容量上限、优雅停机。如果你没有足够的精力去维护这些东西，老老实实用官方异步包装器是更稳的选择。

3. 救回百万数据的三行代码，到底写了什么

3.1 核心三行（简化版）与逐行解读

事故现场最重要的一件事，是先保住那 112 万条日志，而不是急着改代码。当时消费者线程已经死了，队列里的数据还在内存里。我做了三件事，简化以后就是下面这三行：

while (_orderLogQueue.Reader.TryRead(out var evt)) _rescueFileSink.Emit(evt); // 第1行：手动排空积压，绕过硬掉的消费者 _rescueFileSink.Flush(); // 第2行：把兜底写入器的缓冲强制落盘 _orderLogQueue.Writer.TryComplete(); // 第3行：标记队列结束，给后续重建铺路

第 1 行用TryRead()非阻塞地把队列里现存的事件一个个读出来，然后写进一个我专门准备的文件兜底写入器。为什么不用原来的消费者？因为那个线程已经死了，而且它死在一条坏数据上，现在让它重新跑起来还会死在同一条数据上。手动排空时我可以自己控制异常处理，读到坏数据就跳过，绝不让单条污染整个批次。

第 2 行是强制刷新。如果写到文件后只依赖系统缓冲，数据还在操作系统的页缓存里，不能算真正安全。Flush()把写入器内部缓冲强制推到磁盘，这一步做完，这批日志才真正落袋为安。

第 3 行是收尾。TryComplete()之后，生产端不能再往队列里写，读取端也迟早会收到“队列结束”的信号。如果不做这一步，旧队列会一直存在，新老消费者逻辑容易打架，也不方便后面统一重建链路。

3.2 为什么能救：内存里的数据只要没被清，就有办法拿回来

很多人可能会想，112 万条日志，凭什么三行代码就能救回来？关键在于 Channel 队列里存的不是字符串，而是完整的LogEvent对象。只要进程没有退出，队列没有被 Clear，数据就还在内存里。所谓“日志丢了”，很多时候只是“没有消费者去把它写在持久化介质上”，并不是事件本身消失了。

当时还有一个前提：我不能随随便便重启进程。一旦进程退出，Channel 里的数据全部蒸发，那才是真的没了。所以我先稳住进程，把队列里的数据掏干净，最后才去改进代码。如果你也碰到类似情况，第一反应千万别是“重启试试”，而是“先把现场导出”。

3.3 完整修复：消费者循环为什么必须带异常隔离

临时救完火之后，真正的修复是把消费者循环彻底重写。我后来的循环长这样：

private static async Task ConsumeLogLoopAsync( ChannelReader<LogEvent> reader, CancellationToken ct) { var batch = new List<LogEvent>(capacity: 1000); await foreach (var evt in reader.ReadAllAsync(ct)) { batch.Add(evt); if (batch.Count < 1000) continue; try { await _searchWriter.WriteBatchAsync(batch, ct); } catch (Exception ex) { _degradedFileSink.Write(batch); _degradedFileSink.Flush(); } batch.Clear(); } }

核心变化有三个。第一，单个事件不再立即写，而是攒成 1000 条一批，批量写入大幅降低下游压力。第二，写入整批失败时，不抛出异常让循环死掉，而是把这一整批降级写到本地文件，保证数据不丢。第三，用ReadAllAsync(ct)替代手写while (true)，配合CancellationToken能优雅退出，进程停止时先排空队列再结束。

这里还要注意一个顺序问题：排空队列和调用Complete()的顺序。如果你先把队列标记为完成，还在工作的生产线程再写入时会被拒绝，这些新产生的日志反而可能丢。正确做法是先让生产端停下来，或者先排空，最后再 Complete。我当时是先排空再 Complete，这样生产端剩余和消费端剩余互相不干扰。

4. AsyncLocal 陷阱标红：上下文丢失与乱串都是它

4.1 你以为的“线程本地”，其实是“逻辑调用上下文”

数据救回来后，复盘时又发现一个严重问题：日志虽然都有了，但很多日志的TraceId、UserId、OrderId字段是空的，甚至有几条日志的TraceId串到了完全不相关的请求上。追根溯源，问题几乎都出在 AsyncLocal 上。

很多人第一次接触 AsyncLocal，会把它理解成“线程上的静态变量”，这是一个要命的误解。AsyncLocal 的值不是绑在线程上的，而是绑在“逻辑调用上下文”上的。在 async/await 链路里，它会随着执行流程从一个线程流到另一个线程，像是接力棒而不是钉在墙上的牌子。所以你不能用“这个线程之前跑过什么”去推断 AsyncLocal 的值，也不能指望“换了个线程就一定读不到旧值”。

Task.Run默认会携带 ExecutionContext，所以多数情况下 AsyncLocal 会跟着流进后台任务。但是，一旦有代码主动调用ExecutionContext.SuppressFlow()，或者你把任务丢进一个隔离的执行上下文里，它就不会流了。反过来，如果该流的没流，你不做处理，那就是丢上下文；如果不该留的留下了，你没清理，那就是污染别的日志。

4.2 陷阱一：后台消费线程读不到请求上下文

自研 Channel 消费者住在后台线程里，它想读HttpContext、读请求级的 TraceId，统统读不到。因为请求上下文本来就没有流动到后台线程。这个问题的表象是：日志能写出来，但上下文字段全是 null，日志等于白写。

这里有一个和 Serilog 相关的重要细节：Serilog 的LogContext属性是在调用点创建LogEvent时就快照下来的。也就是说，只要你是在请求线程上调用Log.Information(...)，即使消费者线程没有 AsyncLocal，LogEvent 里的属性也还在。真正会踩坑的是下面几种情况：

第一，日志调用点本身在Task.Run内部，而这个后台任务被SuppressFlow隔离了，写日志的线程上没有请求上下文。第二，你自己封装了一套“延迟增强”机制，把自定义 Enricher 放到了消费者线程才执行，让它在读出日志事件时才去读取 Amibent 状态。第三，外层请求的上下文已经被usingDispose 掉了，后台任务才开始写日志，这时候当然拿不到。

我的修复方式是显式捕获、显式恢复，不赌框架的默认行为：

var ambientTrace = TraceContext.TraceId; var ambientUser = TraceContext.UserId; _ = Task.Run(async () => { using var guard = TraceContext.Open(ambientTrace, ambientUser); Log.Information("后台订单补偿任务完成，订单 {OrderId}", orderId); });

关键在于，捕获发生在请求线程上，恢复发生在后台任务的开头。只要这两个动作成对出现，后台日志的上下文就是完整的。

4.3 陷阱二：上下文悄悄泄漏到无关日志里

另一个坑比丢上下文更隐蔽，就是上下文泄漏。场景是这样的：中间件里调用LogContext.PushProperty("UserId", userId)，本意是给当前请求的日志都加上 UserId。但如果忘了把返回的IDisposable释放，或者await之后逻辑没走完就返回了，属性就不会被 Pop。

在同步时代，这个 bug 造成的污染范围最多是一个线程上的后续日志。但在异步时代，AsyncLocal 会顺着 ExecutionContext 流到线程池上后续无关的任务里，于是另一个请求、另一条后台任务写出来的日志，可能莫名其妙带着上一个请求的 UserId。错误数据比没有数据更危险，排查的时候能把人绕晕。

反面教材长这样：

// 反面教材：PushProperty 的返回值没有被 Dispose LogContext.PushProperty("UserId", userId); await _next(context); // 请求结束了，属性还在 AsyncLocal 里残留

正确写法永远是用using包裹：

using (LogContext.PushProperty("UserId", userId)) { await _next(context); }

PushProperty返回的对象在 Dispose 时会 Pop 掉属性，确保请求结束上下文被清理。这是一个看起来小到不能再小的细节，但异步化之后它就是日志错乱的元凶。

4.4 正确姿势：流与不流，都要显式处理

结合这次事故，我把处理 AsyncLocal 的经验总结成几条硬规则。

规则一：PushProperty和Pop必须成对，优先用using写法，绝对不要让属性跨出它所属的逻辑作用域。规则二：跨线程传值要显式捕获、显式恢复，哪怕你知道它默认会流，也不要赌。因为一旦你后来加了SuppressFlow或者换了线程模型，日志上下文会悄悄失效。规则三：后台任务应该有自己独立的日志作用域，不要继承请求上下文。如果确实需要关联链路，就把 TraceId 作为普通参数显式传进去，而不是靠 AsyncLocal 偷偷带过去。规则四：不要误信“用了ConfigureAwait(false)就会丢 AsyncLocal”的说法。ConfigureAwait(false)影响的只是同步上下文，AsyncLocal 跟着逻辑上下文走，不会因为切换线程就消失。这个误解让不少人白加了一堆没用的代码。

5. 日志场景自查清单与速查表

5.1 症状、原因与解法速查表

这次事故处理完后，我做了一张速查表，后面再碰到类似日志问题时直接对着查，效率高很多。

5.2 我踩坑后沉淀的几条规律

日志系统一定要像业务系统一样有监控。队列积压量、消费者存活状态、写入失败次数，这三个指标能救大命。我当时如果早一点在队列上挂一个计数探针，消费者死掉之后马上就会告警，根本不会等到 112 万条积压。

遇到大积压千万不要急着重启。进程一退出，内存队列里的数据全部蒸发。先稳定住进程，把队列里的东西导出到安全介质，再谈代码修复。这次之所以能靠三行代码救回数据，靠的就是“先保住现场”这个朴素的原则。

最后还有一条设计上的体会：生产链路越简单越不容易出事。异步日志看着多了一层队列，其实是把复杂度转移到了消费者生命周期管理上。如果你没有足够的时间去维护消费者循环、异常降级、优雅停机这些逻辑，那官方WriteTo.Async(...)是远比自研更稳的选择。日志这个东西，平时没人注意它，一旦出事，它就是唯一的救命稻草。