手写日志框架：理解原理、设计管道与性能调优

1. 从一次“有日志但等于没日志”的线上排查看起

1.1 日志里只有心跳，没有真相

上一周我排查一个历史服务的偶发超时问题，翻了大半天日志，最后发现日志文件里满满当当全是心跳、健康检查和定时任务的记录，真正出问题的那个请求连影子都没有。那种感觉做过服务端的人都懂：不是没有日志，而是日志系统不具备“组织事实”的能力，信号被噪音彻底淹没了。

那次经历让我重新想明白一件事——日志框架表面上是“往控制台或文件里写字的工具”，但它在诊断体系里的真实身份是“事实收集与过滤管道”。你写不写日志是一回事，日志框架能不能帮你按领域、按级别、按上下文把事实快速捞出来，是另一回事。这也正是“日志框架原理、手写日志框架学习”这两个话题最有价值的交叉点：只有理解框架底层在做什么，你才知道怎么用它做诊断，才知道为什么有些日志写得让人想砸键盘。

1.2 日志框架真正承担的四件事：分类、分级、过滤、格式化

你可以把任何成熟的日志框架拆成四层能力，缺一层都不算框架：

• 分类（Category）：每条日志从哪个组件、哪个类、哪条业务链路来。内置框架通常默认用类全名作为类别名，OrderService和PaymentService从一开始就被区隔开。分类的价值在于让“故障域”和“日志域”能对上号，排查时直接进对应的子目录翻日志就行。
• 分级（LogLevel）：日志从 Trace 到 Critical 的严重程度。没有分级，生产环境就只能全量记录或者全量丢弃；有了分级，才能在“不留噪音”和“不漏事实”之间做权衡。
• 过滤（Filter）：按“类别 + 级别”的组合决定哪些日志真正落盘。过滤不是打印逻辑的一部分，而是独立策略，这意味着你可以不修改业务代码，只改配置就临时放大某个子系统的日志级别。
• 格式化（Formatter）：把一条日志的事件时间、级别、类别、消息、上下文、异常转换成最终写出去的样子。纯文本、键值对、JSON 都是格式化策略的差异，而结构化程度直接决定了日志能不能被检索系统消费。

理解了这四件事，你就会发现日志框架真正卖的不是“打印”，而是“管道加策略”。诊断能力的高低，体现在这四件事的设计是否优雅、灵活、高效。

1.3 为什么说直接封装 Console.WriteLine 不是日志框架

我见过不少团队所谓的“自研日志框架”就是封了一层静态类，内部Console.WriteLine($"xxx: {msg}")。说实话，这连日志框架的门都没摸到。

问题不在于打印动作本身，而在于它缺了上面说的四层结构：没有级别就没有办法一键降噪；没有类别就没有办法按业务域快速拉取日志；没有过滤就没有办法在诊断时定向放大；没有格式化就没有办法让日志被后续的检索分析系统消费。另外Console.WriteLine在并发下是对输出流加锁的，高吞吐业务里直接把日志写到控制台会拖慢业务线程。生产环境里控制台日志只适合调试，不适合作为持久化通道。

所以“手写日志框架”这件事，我理解的目标不是让你自造一个轮子替代现成方案，而是通过从零搭一遍管道，把上面四件事在你脑子里变成具体的代码结构。等再看内置框架或者第三方框架时，看到的就不再是“一堆神秘 API”，而是一套你心里有数的设计。

2. 手写一个最小的日志框架：核心类型与第一个可运行版本

2.1 先定契约：LogLevel、LogEntry、ILogger、ILoggerProvider

手写框架的第一步不是写实现，而是定接口。接口就是契约，后面所有策略都围绕着契约展开。我这里选了一个接近内置框架的简化模型，方便你以后对照学习。

先定义日志级别。有一个细节值得注意：数值从 Trace=0 开始递增，None 最大。这样设计是为了让“阈值过滤”变成一次区间判断，级别越高的日志数值越大，只要level >= minLevel就放行，非常直观：

public enum LogLevel { Trace = 0, Debug = 1, Information = 2, Warning = 3, Error = 4, Critical = 5, None = 6 }

再定义一条日志的完整记录。我用了record类型，因为日志记录天然是只读数据，值语义也方便后续序列化。注意字段的选择：

public sealed record LogEntry( DateTimeOffset Timestamp, LogLevel Level, string Category, string Message, Exception? Exception, IReadOnlyDictionary<string, object?>? State);

这里我刻意把Exception和State分开，而不是揉成一个字符串。原因是异常有异常的结构化字段（类型、消息、堆栈），业务上下文有上下文的字段（订单号、用户ID），两者混在一起后续检索会非常痛苦。

然后是核心接口。框架的业务代码只依赖这两个接口，输出到哪、怎么过滤全都是可替换实现：

public interface ILogger { bool IsEnabled(LogLevel level); void Log(LogLevel level, string message, Exception? exception = null, IReadOnlyDictionary<string, object?>? state = null); } public interface ILoggerProvider { ILogger CreateLogger(string categoryName); }

2.2 LoggerFactory：provider 注册、类别名与 logger 缓存

有了接口，接着实现LoggerFactory。它的职责有三个：管理ILoggerProvider列表、按类别名创建 logger、缓存创建结果。缓存这一点很容易被忽略，但非常重要——如果一个服务每秒打千条日志，每次都去遍历 provider 列表现做组合，性能会很差。

public sealed class LoggerFactory { private readonly object _sync = new(); private readonly List<ILoggerProvider> _providers = new(); private readonly Dictionary<string, ILogger> _cache = new(); private readonly Func<string, LogLevel, bool> _filter; public LoggerFactory(Func<string, LogLevel, bool>? filter = null) { _filter = filter ?? ((category, level) => level >= LogLevel.Information); } public LoggerFactory AddProvider(ILoggerProvider provider) { lock (_sync) { _providers.Add(provider); // 已有缓存失效，后续创建 logger 时会重新组合 provider _cache.Clear(); } return this; } public ILogger CreateLogger(string categoryName) { lock (_sync) { if (_cache.TryGetValue(categoryName, out var logger)) return logger; var targets = new List<ILogger>(); foreach (var provider in _providers) targets.Add(provider.CreateLogger(categoryName)); var composite = new CompositeLogger(categoryName, _filter, targets); _cache[categoryName] = composite; return composite; } } }

CompositeLogger是这里最核心的机制：业务代码拿到的 logger 其实是一个“壳”，它内部持有所有输出目标，并统一执行过滤和分发：

internal sealed class CompositeLogger : ILogger { private readonly string _categoryName; private readonly Func<string, LogLevel, bool> _filter; private readonly IReadOnlyList<ILogger> _targets; public CompositeLogger(string categoryName, Func<string, LogLevel, bool> filter, IReadOnlyList<ILogger> targets) { _categoryName = categoryName; _filter = filter; _targets = targets; } public bool IsEnabled(LogLevel level) => _targets.Count > 0 && _filter(_categoryName, level); public void Log(LogLevel level, string message, Exception? exception = null, IReadOnlyDictionary<string, object?>? state = null) { if (!IsEnabled(level)) return; var entry = new LogEntry( DateTimeOffset.UtcNow, level, _categoryName, message, exception, state); foreach (var target in _targets) target.Log(level, message, exception, state); } }

这段代码对应着理解现成框架的一把钥匙：你调用 logger 时，其实同时在向所有已注册的 provider 广播日志。增加一个输出目标（文件、数据库、日志采集系统），都只是往 factory 里多注册一个 provider 而已，业务代码完全无感。

2.3 模板解析与消息格式化：别小看花括号

下面是很多人写日志框架时最容易敷衍、但恰恰是最有价值的一环：消息模板。logger.Log(LogLevel.Information, "订单 {OrderId} 已创建", state)这一句看起来只是格式化字符串，实际上“模板字符串 + 参数键值对”本身就是结构化日志的雏形。

我用一个简单的一次扫描渲染方法来实现模板替换。为什么不直接用string.Replace循环处理？因为Replace是逐个替换，如果某个字段的值恰好包含另一个字段名，就可能发生二次替换，导致输出错乱。一次扫描虽然代码多几行，但边界行为完全可控：

public static class TemplateRenderer { public static string Render(string template, IReadOnlyDictionary<string, object?>? values) { if (string.IsNullOrEmpty(template)) return template ?? string.Empty; if (values == null || values.Count == 0) return template; var sb = new StringBuilder(template.Length + 32); int pos = 0; while (true) { int start = template.IndexOf('{', pos); if (start < 0) { sb.Append(template, pos, template.Length - pos); break; } int end = template.IndexOf('}', start); if (end < 0) { sb.Append(template, pos, template.Length - pos); break; } sb.Append(template, pos, start - pos); string key = template.Substring(start + 1, end - start - 1).Trim(); if (values.TryGetValue(key, out var value)) sb.Append(value ?? "<null>"); else sb.Append('{').Append(key).Append('}'); pos = end + 1; } return sb.ToString(); } }

这里有个值得记录的经验：模板解析结果应当被缓存。真实框架里，同一段模板字符串会被成千上万条日志反复使用，每次做字符串扫描都是纯粹浪费。手写版本只要把template作为缓存 key、把解析出的占位符列表作为 value，就能省掉大量 CPU 开销。后面第 5 部分我还会再讲性能问题。

2.4 组合起来跑一遍：控制台输出和文件输出

有了核心管道，现在补两个最简单的ILoggerProvider实现。先看控制台 provider，我给它加了简单的颜色区分，级别不同颜色不同，方便人眼扫日志：

public sealed class ConsoleLoggerProvider : ILoggerProvider { public ILogger CreateLogger(string categoryName) { return new ConsoleLogger(categoryName); } private sealed class ConsoleLogger : ILogger { private readonly string _categoryName; public ConsoleLogger(string categoryName) { _categoryName = categoryName; } public bool IsEnabled(LogLevel level) => true; public void Log(LogLevel level, string message, Exception? exception = null, IReadOnlyDictionary<string, object?>? state = null) { var color = level switch { LogLevel.Error or LogLevel.Critical => ConsoleColor.Red, LogLevel.Warning => ConsoleColor.Yellow, _ => ConsoleColor.Gray }; var time = DateTimeOffset.Now.ToString("HH:mm:ss.fff"); var text = $"[{time}][{level}][{_categoryName}] {message}"; if (exception != null) text += Environment.NewLine + exception; lock (Console.Out) { var old = Console.ForegroundColor; Console.ForegroundColor = color; Console.WriteLine(text); Console.ForegroundColor = old; } } } }

文件 provider 要注意并发写文件的问题。多个线程同时写一个文件，日志会交错甚至损坏，所以写文件路径上要加锁。严谨的做法是引入队列异步批量写，但对教学版本来说，一个lock就够了，重点是把框架分层看清：

public sealed class FileLoggerProvider : ILoggerProvider { private readonly object _writeLock = new(); private readonly string _filePath; public FileLoggerProvider(string filePath) { _filePath = filePath; } public ILogger CreateLogger(string categoryName) => new FileLogger(categoryName, _filePath, _writeLock); private sealed class FileLogger : ILogger { private readonly string _categoryName; private readonly string _filePath; private readonly object _writeLock; public FileLogger(string categoryName, string filePath, object writeLock) { _categoryName = categoryName; _filePath = filePath; _writeLock = writeLock; } public bool IsEnabled(LogLevel level) => true; public void Log(LogLevel level, string message, Exception? exception = null, IReadOnlyDictionary<string, object?>? state = null) { var line = $"{DateTimeOffset.Now:O}|{(int)level}|{_categoryName}|{message}"; if (exception != null) line += "|" + exception; lock (_writeLock) { File.AppendAllText(_filePath, line + Environment.NewLine); } } } }

组装代码非常简短，而且整个过程没有业务代码参与，后面的使用方式已经和成熟框架非常接近了：

var factory = new LoggerFactory(filter: (category, level) => level >= LogLevel.Information) .AddProvider(new ConsoleLoggerProvider()) .AddProvider(new FileLoggerProvider("app.log")); var logger = factory.CreateLogger("OrderService"); logger.Log(LogLevel.Information, "订单 {OrderId} 已创建", state: new Dictionary<string, object?> { ["OrderId"] = 20240315 }); logger.Log(LogLevel.Error, "扣款失败", new InvalidOperationException("余额不足"), state: new Dictionary<string, object?> { ["OrderId"] = 20240315, ["Amount"] = 99.5m });

到这里，第一个可运行的极简日志框架就搭完了。它当然没法直接拿到生产环境去用，但你已经能看清楚：日志输出路径、过滤策略、消息格式化，这三者彼此独立，可以任意替换组合。

3. 框架原理深挖：内置日志框架的几个关键设计为什么是“对的”

3.1 过滤逻辑的走向：级别阈值、按类别覆盖、自定义过滤

自己搭过一遍之后，再回看内置框架的过滤设计，会由衷觉得它的分层是对的。内置框架的过滤策略不是简单的一个全局阈值，它支持“按类别树逐层覆盖”。什么意思呢？

• 全局有一个最低级别，比如Information，所有类别默认都要达到这个级别才输出。
• 某个子系统需要临时调详细时，可以单独把该类别（或其前缀）的最低级别降到Debug，其他类别不受影响。
• 最后还可以再加自定义过滤委托，对具体的级别、类别、消息内容做编程式判断。

这三层过滤是“与”的关系，必须同时满足才放行。这个设计最救命的地方在于诊断时不需要改业务代码，只要调整配置，就能让某个长期保持安静的服务突然输出完整调试信息。我实际排查问题时，最常用的操作就是给目标服务临时开 Debug，压测复现之后再关掉。

手写框架时，我把过滤写成Func<string, LogLevel, bool>，本质上已经和内置框架的过滤模型对齐了。唯一简化的是没有做“类别前缀匹配”，比如Category = "OrderService.Payment"能同时被OrderService的规则覆盖。这一步在你自己的实现里并不难补：把规则存成有序列表，拿 category 做StartsWith前缀匹配，取最深的命中规则即可。

3.2 作用域：怎么把“请求上下文”串进同一条链路

日志框架里另一个容易被忽视、但诊断价值极高的设计是“作用域（Scope）”。作用域解决的是这样一个问题：一条业务请求从入口到出口会横跨多个类、多个方法，如果每个方法都往日志里手工传订单号，代码会非常丑陋，而且漏传的情况防不胜防。

作用域的思路是：在某段代码执行期间压入一个上下文对象，这段代码里产生的所有日志，都自动携带这个上下文。用using语句包住业务逻辑，进入时压栈，退出时自动弹栈：

public static class ScopeContext { private static readonly AsyncLocal<Stack<ScopeState>> _scopeStack = new(); public static IDisposable Push(IEnumerable<KeyValuePair<string, object?>> state) { var scope = new ScopeState(state); var stack = _scopeStack.Value ??= new Stack<ScopeState>(); stack.Push(scope); return new ScopeDisposable(); } public static IReadOnlyList<ScopeState> Current => _scopeStack.Value?.ToArray() ?? Array.Empty<ScopeState>(); private static void Pop() => _scopeStack.Value?.Pop(); private sealed class ScopeDisposable : IDisposable { public void Dispose() => Pop(); } }

这里的关键是AsyncLocal<T>。在异步编程非常普遍的今天，await后面的代码很可能跑在不同的线程上。如果用ThreadLocal，上下文会在await之后丢失；而AsyncLocal会随逻辑执行流自动流传，这正是业务请求上下文需要的语义。

有了作用域，日志方法在组装LogEntry时，可以把ScopeContext.Current里的所有键值对并入 State。这样就会看到下面的效果：订单入口 push 了OrderId=abc-123，后面所有子模块的日志都带上这个字段，排查时一眼就能把整条请求链路捞出来。

3.3 异常与状态对象：日志不该只记录一个字符串

新手写日志最常见的坏习惯是只记异常消息：logger.Log(LogLevel.Error, ex.Message)。这句话把异常最重要的两个信息丢了——堆栈和内部异常。

先说堆栈。Exception.Message只包含一个简短描述，比如“余额不足”；但真正定位问题需要看到异常抛出位置的调用栈，可能需要exception.ToString()。ToString()会输出异常类型、消息、堆栈跟踪，以及InnerException的完整链。

再说结构化。异常对象本身有不少值得单独索引的字段：Type、Message、HResult、StackTrace、InnerException。如果日志系统支持结构化检索，把这些字段拆开比混在全部堆栈文本里更有用。这也是为什么前面定义LogEntry时把Exception单独设成一个字段，而不塞进State。

写日志时的正确姿势是：异常和上下文都保留原始对象，让格式化层决定最终输出。文件诊断时用完整ToString()，接入日志采集系统时序列化成 JSON 字段，完全不必改业务代码。

4. 续写手写框架：上下文关联、结构化日志与链路追溯

4.1 给日志加上 CorrelationId：一次请求一个编号

我在真实排障时最常做的一个操作，就是从入口日志里复制一个请求编号，然后拿它去过滤整条调用链上的所有日志。这个编号在业界的通用叫法是 RequestId 或 CorrelationId。

手写框架里要支持这个能力其实很简单：入口处生成一个 ID，把它作为作用域压入上下文，让这条请求里的所有日志自动带上它。可以模拟一个请求处理入口：

public static class RequestProcessor { public static void Process(int orderId) { var correlationId = Guid.NewGuid().ToString("N"); var scopeState = new Dictionary<string, object?> { ["CorrelationId"] = correlationId, ["OrderId"] = orderId }; using (ScopeContext.Push(scopeState)) { var logger = LogFactory.GetLogger("RequestProcessor"); logger.Log(LogLevel.Information, "开始处理订单"); // 下游方法使用同一个 factory 创建的 logger， // 日志里会自动带出 CorrelationId 和 OrderId。 OrderService.Process(orderId); } } }

这里为什么不用线程 ID 替代？因为线程 ID 只能证明日志出现在同一个线程里，不能证明它们属于同一次业务请求。线程池环境下，同一个线程可能交替处理多个请求，同一个请求也会在 await 前后跳到不同线程。CorrelationId 绑定的是“逻辑执行流”，不是物理线程，这才是能在并发体系里串联日志的原因。

4.2 结构化输出：从纯文本升级到 JSON

前面第 2 部分的文件 provider 输出的是纯文本。纯文本日志人眼友好，但机器检索很难受，比如你想查“OrderId=20240315 的日志”，只能靠正则碰运气。如果日志写成了结构化字段，检索系统就能精确匹配字段值。

结构化输出并不神秘，只需要在 provider 的格式化环节把LogEntry序列化成一行 JSON。手动写一个JsonLoggerProvider很容易，核心字段保持稳定即可：

private void WriteEntry(LogEntry entry) { var timestamp = entry.Timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffZ"); var message = TemplateRenderer.Render(entry.Message, entry.State); var fields = new Dictionary<string, object?> { ["ts"] = timestamp, ["level"] = entry.Level, ["category"] = entry.Category, ["message"] = message }; // 合并业务状态字段 if (entry.State != null) foreach (var kv in entry.State) fields[kv.Key] = kv.Value; // 异常单独拆字段 if (entry.Exception != null) { fields["excType"] = entry.Exception.GetType().FullName; fields["excMessage"] = entry.Exception.Message; fields["excStack"] = entry.Exception.ToString(); } // 合并作用域上下文 foreach (var scope in ScopeContext.Current) foreach (var kv in scope) fields.TryAdd(kv.Key, kv.Value); lock (_writeLock) { File.AppendAllText(_filePath, System.Text.Json.JsonSerializer.Serialize(fields) + Environment.NewLine); } }

这段代码把多层信息拼进同一个输出：事件时间、级别、类别、格式化后的消息、业务状态、异常字段、作用域上下文。到这一步你已经可以对接常见的日志采集和检索系统了，文件里的每一行都能被解析成独立文档，按字段过滤。

4.3 日志与诊断事件体系的分工：什么时候用日志，什么时候用 Activity

手写日志框架写到这里，我还想澄清一个容易被混淆的点：日志框架和链路追踪是两套互补的东西，不是一回事。

日志回答的是“发生了什么”：扣款失败、订单过期、用户取消。链路追踪（Activity/DiagnosticSource 这套体系）回答的是“这个操作经历了什么、每一段耗时多少”：从网关到服务 A 花了 30ms，服务 A 调用缓存 2ms，调用数据库 18ms。

实际诊断时，我通常先看链路数据，快速定位慢在哪一段，再落到具体服务上翻日志找原因。如果日志框架做了 CorrelationId 和 Scope，它就已经具备了一定的“轻量链路”能力——虽然不如完整 APM 工具精细，但在小团队、小系统里完全够用。这也是我推荐的演进路径：先把手写框架里的作用域和关联 ID 用好，真有需要再引入完整链路追踪。

5. 高频日志场景的性能陷阱与我的调优记录

5.1 最容易忽略的开销：字符串拼接发生在 IsEnabled 之前还是之后

看到这里，你已经能写出一个功能完整的日志框架了。但从“能用”到“能扛住生产流量”，中间还隔着性能这道坎。我在调优手写框架时，踩得最深的坑就是日志消息的构造时机。

看这段反面代码：

logger.Log(LogLevel.Debug, $"用户 {userId} 下单，商品 {productId}，数量 {count}");

这里的问题在于：字符串插值在调用Log之前就会执行，花括号部分的格式化、字符串对象的分配都发生了。如果当前日志级别是Information，Debug根本不会输出，但这些分配已经白白浪费。在高频业务路径上，这种浪费会被放大得非常明显。

正确的做法有两种。第一种是手动先做级别检查：

if (logger.IsEnabled(LogLevel.Debug)) { logger.Log(LogLevel.Debug, $"用户 {userId} 下单，商品 {productId}，数量 {count}"); }

第二种是使用“模板参数延迟传递”的接口，让框架在确认需要输出后再执行真正的格式化。这也是日志框架普遍采用模板方法、而不是直接传拼接完成字符串的深层原因。

5.2 模板缓存与复用：让重复日志不再重复分配

日志有一个显著特征：模板高度重复。一分钟之内可能产生几万条用户 {UserId} 下单，它们的模板字符串完全相同，只是参数值不同。如果不做任何缓存，每一条日志都要重新解析模板、重新分配字符缓冲区，这个浪费完全没有必要。

我在手写框架里加了一个简单的模板缓存：

public static class TemplateCache { private static readonly ConcurrentDictionary<string, ParsedTemplate> Cache = new(); public static ParsedTemplate Get(string template) { return Cache.GetOrAdd(template, t => new ParsedTemplate(t)); } }

ParsedTemplate在构造时扫描一次模板，得到占位符列表，之后每次格式化只需要按固定位置替换参数值，不再重新扫描。这个缓存的收益在高频日志场景非常明显。再进一步，如果你在构建阶段就使用预编译的方式生成日志方法，甚至能省掉模板解析和字典查找，达到接近手写原生代码的性能，这也是静态日志消息助手的核心原理。

5.3 压测数据：优化前后吞吐差异与日志拖垮业务的边界

我简单跑过一轮对比，数据值得记录一下。用第 2 部分的“透明模板渲染 + 每行 JSON 写文件”版本，在普通笔记本上每秒大约能写几万条日志；加上模板缓存、把每个日志参数的Dictionary创建改为复用预分配数组后，吞吐量有明显提升，提升幅度在数倍量级。

有趣的是，真正限制吞吐的往往不是格式化，而是文件写入。所以成熟的日志框架普遍采用“异步写盘 + 批量写入 + 独立后台线程”的架构。我在这里要提醒一句：日志框架的可靠性边界是“绝不能拖垮业务链路”。如果文件系统出现短暂拥塞，异步队列被塞满，正确处理是考虑丢弃部分非关键日志，而不是让业务线程阻塞在日志写入上。生产环境里，我倾向于对 Error 以上级别采用可靠投递，对 Debug/Information 级别采用可丢弃策略，必要时可以按比例采样。

基于这些压测和调优记录，我验证了一件事：手写日志框架的价值不在生产替代，而在于让“日志框架原理”从概念变成肌肉记忆。你亲手搭过一遍管道、亲手优化过一次模板缓存之后，再看任何框架的“高性能特性”都不会觉得神秘，因为你知道每一层它到底在做什么。