资讯动态

手写日志框架:从ILogger到Provider与异步队列的完整实践

发布时间:2026/10/22 12:00:40 来源:尧图企业网站定制
1. 日志报警没响关键日志却丢了为什么建议你把日志框架拆开看看1.1 只会用 ILogger 的尴尬我在排查线上问题的时候最怕的不是报错而是连日志都没有。代码里明明写了_logger.LogInformation(开始处理订单:{orderId})运行期日志里却一片安静既没有报错也没有记录。花两小时翻代码最后发现不是业务逻辑错了而是日志框架的过滤配置、Provider 注册顺序和 Category 不对把我们要的信息全部吞掉了。经历过那次之后我就不再满足于“会用 ILogger”而是认真研究日志框架背后到底是怎么流转的并且动手写了一套简化版来验证自己的理解。很多人对日志框架的认知停留在“调ILogger接口方法”这一层。写业务的时候确实够用但一旦涉及诊断问题就来了为什么日志没输出为什么同一个消息打了两遍为什么业务线程被日志拖到超时这些问题不把框架内部结构看清楚就只能靠猜。靠猜排查问题效率极低。1.2 拆开框架的三个直接收益先说清楚这篇文章不是带着你把官方源码一行行读完而是通过手写一个简化但结构完整的日志框架把 LoggerFactory、Logger、Provider、LogLevel、异步写入这些核心概念全部串起来。我自己实践下来的感觉是写一遍比读十遍文档都管用。收益一是可控性。你知道日志从调用到落地经过哪些环节出问题就能快速定位是在生成环节、过滤环节还是输出环节丢的。收益二是诊断能力。线上看到“日志重复”“日志丢失”“日志级别不对”你不会再一头雾水脑子里会有一张完整的流转图。收益三是性能意识。手写过程中你会自然而然地碰到“同步写文件卡业务线程”这个坎然后理解为什么生产环境的日志系统要引入队列为什么有些日志宁可丢弃也不能阻塞主流程。这些经验是单纯调 API 学不到的。2. 日志框架的核心抽象Logger、Level 与 Provider 的关系2.1 三个角色分别干什么先做一个生活化类比。你去银行办事门口有接待员问你办什么业务然后帮你取号、引导你去对应柜台。接待员不负责真正处理业务但他决定你去哪个窗口。柜台里的柜员才真正干活。在日志框架里ILogger就是那个接待员它接收你“记一条日志”的请求然后按照规则把请求分发给一组“柜员”。这组柜员就是ILoggerProvider也就是真正的输出端Console、文件、数据库、远程日志服务都是 Provider 在干活。那ILoggerFactory是什么它是银行的大堂经理负责管理和分配接待员。工厂内部维护着一张“接待员名单”你告诉它你想记录哪个模块的日志Category它给你一个对应名字的ILogger。同一个 Category 会复用同一个 Logger 实例避免频繁创建对象的开销。很多初学者会把 Logger 和 Provider 混为一谈觉得ILogger就是输出日志的。其实它只是一个转发者真正决定日志写到哪里、用什么格式写的是 Provider。搞清楚这一层后面理解“日志为什么没输出”就会容易很多。2.2 日志从调用到落地的完整流转一条日志的完整生命周期可以拆成四个环节。第一个环节是你调用logger.Info(xxx)或logger.LogInformation(xxx)。注意此刻日志还没有被输出它只是被包装成了一个消息对象。第二个环节是日志框架判断这条日志要不要记录。判断依据是 LogLevel也就是 Trace、Debug、Information、Warning、Error、Critical 这几个级别。每个框架通常都有一个最小日志级别比如配置了MinLevel Warning那么 Warning 以下的日志直接丢弃。第三个环节是把消息分发给所有注册的 Provider。这里要留意日志框架是“广播”模式注册了两个 Provider同一条日志就会被写两次一个写 Console一个写文件。第四个环节是 Provider 真正把消息格式化并输出到目标介质。到这里日志才算落地。这四步里每一步都可能出问题。最小日志级别太高日志会在第一步被丢Provider 没注册成功到了第三步就没人接收格式化顺序写错第四步输出的内容就是乱的。后面诊断部分我详细展开。2.3 从最原始的 Console 输出反推抽象边界假如没有框架你可能会这么写public static class LogHelper { public static void Info(string message) { Console.WriteLine($[INFO] {DateTime.Now:yyyy-MM-dd HH:mm:ss} {message}); } }这个 helper 在小型项目里够用但问题很多硬编码了输出端想改成写文件就得改工具类只有一个全局方法没法按模块分开控制级别一旦代码里到处直接调用 Console后面想接入远程日志服务就是一场噩梦。于是你自然会想到抽接口把“记录日志的动作”和“输出的目的地”分开。这就诞生了两个核心接口一个是开发者直接面对的 Logger 接口一个是负责输出的 ProviderSink接口。而工厂类负责把两者组装起来。整个日志框架的骨架其实就是这三个角色和两个接口之间的协作关系。public interface ILogSink { bool IsEnabled(LogLevel level); void Write(LogLevel level, string category, string message); }Provider 之所以需要单独实现IsEnabled是因为不同输出端可以有不同的策略。比如文件日志可能只想记录 Warning 以上Console 却希望什么都打出来。这种差异如果只在工厂层面统一过滤就做不到。3. 手写第一版Provider 模式与 Category 隔离3.1 接口设计先定协议再写实现开始写代码之前我强烈建议先把接口定下来。协议定了后面扩展组件就是增量的活。我需要四个东西LogLevel枚举、ILogSink接口输出端、IAppLogger接口开发者入口、AppLoggerFactory组装工厂。public enum LogLevel { Trace 0, Debug 1, Information 2, Warning 3, Error 4, Critical 5 } public interface ILogSink { bool IsEnabled(LogLevel level); void Write(LogLevel level, string category, string message); } public interface IAppLogger { void Log(LogLevel level, string message); void Info(string message); void Warning(string message); void Error(string message, Exception? exception null); }这里有个关键设计IAppLogger是面向业务代码的先不暴露 Category因为业务代码不该关心这个。Category 由工厂在创建 Logger 时注入。这样不同模块拿到的 Logger 天然就带上了自己的身份标识输出时可以区分来源。3.2 工厂接管 Provider 注册接下来是工厂和默认 Logger 的实现。public sealed class AppLoggerFactory { private readonly object _gate new(); private readonly ListILogSink _sinks new(); private readonly Dictionarystring, IAppLogger _loggers new(); public void AddSink(ILogSink sink) { lock (_gate) { _sinks.Add(sink); } } public IAppLogger CreateLogger(string category) { lock (_gate) { if (_loggers.TryGetValue(category, out var existing)) { return existing; } var logger new AppLogger(_sinks, category); _loggers[category] logger; return logger; } } } public sealed class AppLogger : IAppLogger { private readonly ILogSink[] _sinks; private readonly string _category; private readonly LogLevel _minLevel; public AppLogger(IListILogSink sinks, string category, LogLevel minLevel LogLevel.Trace) { _category category; _minLevel minLevel; _sinks sinks.ToArray(); } public void Log(LogLevel level, string message) { if (level _minLevel) { return; } var line ${DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} [{level}] [{_category}] {message}; foreach (var sink in _sinks) { if (sink.IsEnabled(level)) { sink.Write(level, _category, line); } } } public void Info(string message) Log(LogLevel.Information, message); public void Warning(string message) Log(LogLevel.Warning, message); public void Error(string message, Exception? exception null) Log(LogLevel.Error, exception is null ? message : ${message}{Environment.NewLine}{exception}); }这里有一个细节值得展开为什么AppLogger接收的是_sinks.ToArray()这个快照因为_sinks可能被后续AddSink修改而 Logger 实例已经被业务代码拿着了。用数组快照保证遍历的时候不会出现并发修改异常同时每次创建 Logger 时都把当前已有的 Sink 固定下来。这也是“Logger 持有 Provider 集合”的一种具体实现方式。3.3 为什么官方把 Logger 又包了一层 ILogger很多人用官方抽象库时会困惑有了ILoggerFactory.CreateLogger(CategoryName)为什么还要ILoggerT直接ILoggerT拿到的 LoggerCategory 自动就是typeof(T).FullName。这个设计的好处是强类型和免拼字符串。你用ILoggerOrderService的时候Category 自动是OrderService的命名空间加类名不会出现手写字符串拼错的问题。而且在依赖注入容器里ILoggerT可以直接注册成泛型解析的时候框架自动帮你把 T 的类型名作为 Category。我手写的这个简化版本没有加泛型包装但思路是通用的Category 就是日志的分组标签你既可以手写字符串也可以用类型全名充当。诊断的时候看到[OrderService]标签立刻就知道是哪段代码打的日志这就是 Category 隔离的意义。3.4 写一个控制台 Sink 验证跑通public sealed class ConsoleSink : ILogSink { private readonly LogLevel _minLevel; public ConsoleSink(LogLevel minLevel LogLevel.Trace) { _minLevel minLevel; } public bool IsEnabled(LogLevel level) level _minLevel; public void Write(LogLevel level, string category, string message) { var previousColor Console.ForegroundColor; Console.ForegroundColor level LogLevel.Warning ? ConsoleColor.Red : level LogLevel.Information ? ConsoleColor.Cyan : ConsoleColor.Gray; Console.WriteLine(message); Console.ForegroundColor previousColor; } }然后组装var factory new AppLoggerFactory(); factory.AddSink(new ConsoleSink(LogLevel.Debug)); var orderLogger factory.CreateLogger(OrderService); orderLogger.Info(订单已创建订单号:{0}, ...);跑到这里一个可用的手写日志框架就算跑通了。它能按 Category 区分来源能按 Level 过滤后续加文件输出也不需要改业务代码。套用一句行话面向接口编程的好处在这一刻就体现出来了。4. 向多 Provider 演进Console 与 File 共存4.1 新增文件 SinkLogger 一行没改现在我要加一个文件输出端。做法很简单实现ILogSink接口然后在工厂里注册。public sealed class FileSink : ILogSink, IDisposable { private readonly StreamWriter _writer; private readonly LogLevel _minLevel; private long _writeCount; public FileSink(string filePath, LogLevel minLevel LogLevel.Warning) { _minLevel minLevel; var stream new FileStream(filePath, FileMode.Append, FileAccess.Write, FileShare.Read); _writer new StreamWriter(stream) { AutoFlush true }; } public bool IsEnabled(LogLevel level) level _minLevel; public void Write(LogLevel level, string category, string message) { _writer.WriteLine(message); Interlocked.Increment(ref _writeCount); } public void Dispose() { _writer.Flush(); _writer.Dispose(); } }注意构造函数里的FileShare.Read。这个参数的意思是文件写入时允许其他进程以只读方式打开这个文件比如你用记事本或日志采集 agent 查看日志而不会直接报“文件被占用”。这个细节对运维场景特别重要我用第一次实验时没加结果日志 agent 读取文件一直失败。注册方式没有任何变化factory.AddSink(new ConsoleSink(LogLevel.Debug)); factory.AddSink(new FileSink(logs/app.log, LogLevel.Warning));现在同样一条 Info 日志会同时出现在控制台和文件里而 Warning 以下的日志只会进控制台不会进文件。这种“不同输出端有不同的详细程度”的需求用 Provider 模式做起来非常干净。新增输出能力原有代码一行不改这就是开闭原则的实际例子。4.2 格式化与写入时序的坑多 Provider 共存后第一个坑就是格式不统一。比如 ConsoleSink 里我用的是“时间 级别 Category 消息”的格式而 FileSink 想输出成 JSON 方便日志分析系统解析。怎么办常见的做法是引入一个格式化器Formatter把“格式化消息”这个动作从 Provider 里剥离开。格式化器负责把日志对象渲染成字符串Provider 只负责把字符串写到目的地。稍微复杂一点的框架还会针对不同 Provider 注册不同的格式器。官方的 Console Provider 和 OpenTelemetry Provider 就是各自处理各自的格式。我手写实现时为了简单直接让 Logger 在分发前先统一拼好字符串。演示没有问题但你心里要清楚真实项目里日志会携带结构化信息对象、事件 ID、异常堆栈把这些信息转成字符串应该尽量延后最好在输出端再做格式化。这样做的好处很大比如想输出 JSON 格式时你可以拿到原始字段而不是去解析拼好的字符串。另一个坑是写文件的缓冲问题。如果不做AutoFlush日志会积在 StreamWriter 的内存缓冲区里程序崩溃时缓冲区内容直接丢光。做了AutoFlush每次写都会刷盘性能又会受影响。这个矛盾是日志框架性能优化的核心话题之一下一节专门讲。4.3 官方框架还多做了哪些事到了这一步我手写的框架和官方抽象库的结构已经很接近了。官方本质上就是ILoggerFactory管 Provider 集合Logger是分发器Provider是输出端外加一套 Filter 规则和一个依赖注入容器。但官方还有两个我暂时没做的东西值得你知道。一是日志作用域Scope。它是IDisposable用来给一批日志附加上下文信息。比如处理某个请求时你希望这个请求过程中打的所有日志都带上同一个TraceId。官方用BeginScope实现底层是在 Provider 内部维护一个作用域栈。我手写的版本没有做因为 scope 的核心难点是对线程上下文的传播代码量不小。二是日志源生成器。官方推荐用[LoggerMessage]特性让编译期生成高性能的日志调用代码避免字符串模板的装箱和格式化开销。这个属于性能优化了解即可不影响理解原理。5. 性能与稳定性异步队列和日志丢弃策略5.1 同步写 IO 为什么扛不住把日志写到控制台还好如果写到文件、网络或者数据库IO 延迟是毫秒到几十毫秒级别可能出现比你业务逻辑还慢的情况。打个比方你的业务线程像一辆送餐车正常跑一趟 5 分钟。现在每送一单都要求司机先绕道 500 公里外取个东西送餐效率会瞬间崩掉。同步写日志就是这个意思——Logger是在业务线程里调用的Provider同步写文件等于让业务线程替日志服务干活。解决思路很清晰把“生产日志”和“输出日志”解耦。业务线程只把日志塞进一个队列立刻返回后台专门开一个线程或几个线程消费队列真正去写文件、发网络。这就是生产者-消费者模型。5.2 用 Channel 实现生产者-消费者模型.NET 里实现这个模型我推荐用System.Threading.Channels。它是官方提供的并发队列设计目标就是高性能的生产者-消费者场景。public sealed class AsyncFileSink : ILogSink, IDisposable { private readonly ChannelLogEntry _channel; private readonly Task _worker; private readonly StreamWriter _writer; private bool _disposed; public AsyncFileSink(string filePath, int capacity 1024) { var options new BoundedChannelOptions(capacity) { FullMode BoundedChannelFullMode.DropWrite, SingleReader true }; _channel Channel.CreateBoundedLogEntry(options); _writer new StreamWriter(new FileStream(filePath, FileMode.Append, FileAccess.Write, FileShare.Read)); _worker Task.Factory.StartNew(ProcessQueueAsync, CancellationToken.None, TaskCreationOptions.LongRunning, TaskScheduler.Default); } public bool IsEnabled(LogLevel level) true; public void Write(LogLevel level, string category, string message) { var entry new LogEntry(level, category, message); // 队列满了直接丢弃并统计丢弃数量 if (!_channel.Writer.TryWrite(entry)) { Interlocked.Increment(ref _droppedCount); } } private async Task ProcessQueueAsync() { await foreach (var entry in _channel.Reader.ReadAllAsync()) { await _writer.WriteLineAsync(entry.ToString()); } } public void Dispose() { if (_disposed) return; _disposed true; _channel.Writer.TryComplete(); _worker.Wait(TimeSpan.FromSeconds(5)); _writer.Flush(); _writer.Dispose(); } } public sealed record LogEntry(LogLevel Level, string Category, string Message) { public override string ToString() ${DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} [{Level}] [{Category}] {Message}; }这个版本有一个我没在代码里标注的动作BoundedChannelFullMode.DropWrite表示队列满的时候新的日志条目会被直接丢弃。对日志系统来说丢失一部分非关键日志比阻塞业务线程导致请求超时要划算得多。这个取舍每个项目要根据日志重要性自己定。5.3 队列满了怎么办背压与降级写到这就要提一个决策点队列容量设多少满了以后是丢弃还是等待。设太多内存压力大。假设置成 10 万条每条日志字符串平均 200 字节那就是 20 MB 起步如果日志里还带异常堆栈轻松上百 MB。设太少日志频繁丢弃排查问题时可能正好丢掉关键信息。我的经验是分场景关键业务日志用有界队列加等待策略宁可让写日志的线程等一下也不能丢普通调试日志用有界队列加丢弃策略记录一个丢弃计数器等排查性能问题时再去看计数器数值。这里还有一个容易忽略的收尾动作进程要正常退出时必须先TryComplete让生产者停止写入再等消费者把队列里剩余的日志全部排空。我见过不少自研日志模块崩溃时丢日志原因就是进程 exiting 事件里直接Environment.Exit(0)后台线程来不及 flush 就死了。5.4 Error 级别需要特殊对待吗日志系统常常会给 Error、Critical 级别开绿色通道。原因很直白Error 是出大事的证据丢失代价最高。有些框架的做法是单独开一个高优先级队列或者干脆对 Error 级别退化为同步写确保它一定落盘。我个人的建议框架可以默认只对 Critical 级别同步写Error 级别走异步但容量较小的专用队列并且不丢弃。这样既保证了关键错误可追溯又不至于让所有错误日志都拖慢业务。至于在官方框架层面有没有这个能力不同版本不同系统实现不一但原理都是这套。6. 诊断实战从“日志没输出”到“日志重复输出”6.1 日志没输出三级过滤逐个查现在回到开头那个场景日志没打出来。有了前面的原理排查链路就很清晰。我会按下面的顺序逐层检查。第一层Logger 实例有没有正确拿到。如果你是手写工厂检查是不是每次CreateLogger都传了不同的字符串导致你以为在用同一个 Category实际拿到了两个不同的 Logger。如果你用的是官方抽象库检查依赖注入容器里有没有在构造函数里要求ILoggerFactory却忘了注册。第二层日志级别过滤。检查创建 Logger 时设置的_minLevel、工厂层有没有全局级别、以及 Provider 自己的IsEnabled。这三处任何一处把级别过滤掉了日志就不会输出。我用一个表格把这几个检查点列出来检查点常见问题排查方式Logger 获取Category 拼写不一致拿到不同实例输出 Category 标签对照Logger 最小级别全局级别设成了 WarningInfo 被吞降低全局级别观察变化Provider IsEnabledConsole 只输出 Error看不到 Debug临时把 Provider 级别设为 TraceProvider 注册AddSink 没调用或调用了但被覆盖检查工厂持有者列表第三层Provider 本身是否可用。比如 FileSink 打开文件路径时抛了异常但异常被静默捕获了日志就无声无息地丢掉了。一个负责任的手写框架Provider 的初始化异常至少应该输出到标准错误而不是吞掉。6.2 日志重复输出Provider 注册的幂等性日志打了两遍是另一个高频问题。出现这种情况九成原因是同一个 Provider 被重复注册了。比如工厂初始化代码被调用了两次AddSink(new FileSink(...))执行了两遍但你只看到一份文件内容里是双份日志。或者官方抽象库的场景里你在多个模块里都对容器调用了AddConsole()。诊断思路很简单在AddSink方法里给每个 Sink 分配一个唯一 ID然后输出注册列表的哈希值看看运行时容器里到底有哪些 Sink。不过最简单的方法其实是看日志内容格式两份日志如果时间戳完全一致只是重复出现多半就是重复注册。另外一个隐藏更深的原因多个工厂实例。如果你的应用同时存在两个AppLoggerFactory实例一个注册了 Console一个注册了 File业务代码拿到了其中一个另一个也在写看起来像“日志从不同地方冒出来”实际上还是注册管理混乱。解决方法是把工厂设计成全局单例或者统一走依赖注入容器。6.3 日志闪烁丢失进程退出与缓冲日志丢失尤其是异步队列模式下丢失是最难排查的一类问题。因为日志“没有发生过”连错误都没有。我踩过的坑是这么一种情况控制台里日志一切正常文件日志却有缺口每次进程重启后最后一次批量刷新的日志总是少几条。后来定位到原因是程序退出时没有等后台消费线程把队列排空。进程退出太快后台线程被强制结束了。解决方法就是我在异步 Sink 里写的那个Dispose调用TryComplete()通知消费者“生产结束了”再用_worker.Wait(TimeSpan.FromSeconds(5))给消费者一个宽限期宽限期内把剩余日志全部刷盘。这个逻辑必须在进程退出钩子里被可靠调用而不是靠垃圾回收。还有一类丢失是磁盘满或者权限问题。FileSink 写文件失败后如果异常被吞掉日志就很安静地丢了。负责任的做法是写失败时尝试输出到备用输出端比如 Windows 事件日志或者System.Diagnostics.Trace至少让运维人员知道日志系统本身坏了。6.4 日志系统的日常体检最后分享一个我自己养成的习惯每个季度给日志系统做一次“体检”。体检项目包括异步队列的丢弃计数是否为 0文件写入是否出现异常日志Provider 的启动时间是否异常日志文件的大小增长是否符合预期。特别是异步队列的丢弃计数它是个非常重要的健康指标。如果计数一直在涨说明日志生产速度长期高于消费速度要么扩容消费线程要么调大队列要么降低冗余日志的级别。日志框架看起来是基础设施里最不起眼的部分但恰恰是这份“不起眼”让它很少被认真审视。真正出问题的时候它又会变成最影响排查效率的环节。手写一个简化版不是为了重复造轮子而是为了在出问题的时候脑子里那张流转图能第一时间把问题指出来。

读完文章,也想定制专属网站?

尧图设计师 24 小时内与您沟通定制方案

免费获取报价 →
↑