后端可观测性【免费下载链接】serilogSimple .NET logging with fully-structured events项目地址https://gitcode.com/gh_mirrors/se/serilog点击查看免费下载本篇基于 Serilog 仓库中 LogContextEnrichmentBenchmark 基准报告net4.5.2 展开聚焦LogContext.PushProperty在纯 .NET Framework 环境下的实测耗时、与裸日志写入的倍数差距并下沉到 LogContext.cs、EnricherStack.cs、LogContextTests.cs 等源码讲清为什么贵、贵在哪、怎么用才划算。读完你将掌握基准结果的正确解读方法、从 LogContext 富化到事件写入的完整调用链、PushProperty 嵌套/压栈的成本构成以及 Clone/Suspend/Reset 等高级 API 的适用场景。一、基准报告概览跑的是什么关联文档是一份 BenchmarkDotNet 基准报告BenchmarkDotNet.Core v0.9.9.0运行环境关键信息如下操作系统Microsoft Windows NT 6.2.9200.0即 Windows Server 2012 / Windows 8 内核处理器Intel(R) Core(TM) i7-3720QM CPU 2.60GHzProcessorCount8计时器TSC时间戳计数器频率 2533306 ticks分辨率约 394.7411 nsCLRMS.NET 4.0.30319.4200064-bit RELEASEJIT 为 RyuJITGCConcurrent Workstation模式ModeThroughput吞吐量模式衡量单位时间内可执行的操作次数被测类型为LogContextEnrichmentBenchmark对应源码 test/Serilog.PerformanceTests/LogContextEnrichmentBenchmark.cs。基准方法共四个其中Bare被标记为[Benchmark(Baseline true)]作为其余三项的缩放基准方法中位数Median标准差StdDevScaled相对基准Scaled-SDBare14.5935 ns0.2010 ns1.000.00PushProperty384.9070 ns2.4957 ns26.610.41PushPropertyNested778.8093 ns51.8017 ns55.463.59PushPropertyEnriched598.1650 ns12.3394 ns41.521.01结论速读在 .NET Framework 4.5.2 目标框架下LogContext.PushProperty单次压栈约 385 ns是裸事件写入约 14.6 ns的 26 倍嵌套两次压栈约 779 ns约 55 倍而在压栈作用域内真实写一条日志PushPropertyEnriched约 598 ns约 41 倍。二、基准方法设计与测试目标对照源码LogContextEnrichmentBenchmark.cs四个方法的构造非常克制专门用来隔离压栈本身与压栈 写日志的成本[GlobalSetup] public void Setup() { _bare new LoggerConfiguration() .WriteTo.Sink(new NullSink()) .CreateLogger(); _enriched new LoggerConfiguration() .WriteTo.Sink(new NullSink()) .Enrich.FromLogContext() .CreateLogger(); }Bare()直接_bare.Write(_event)测量不经过任何富化的纯写入管线成本。其中_event来自 Support/Some.cs 的Some.InformationEvent()通过BindMessageTemplate预构造一个已完成模板解析的LogEvent。PushProperty()using (LogContext.PushProperty(A, B)) { }不写日志纯粹测量属性压栈、作用域退出弹出这一完整生命周期。PushPropertyNested()using嵌套两次PushProperty测量多层压栈/弹栈的叠加成本。PushPropertyEnriched()在PushProperty(A, B)作用域内调用_enriched.Write(_event)测量上下文富化真正介入事件写入时的成本。输出端统一使用 NullSink.csEmit为空实现从而把 sink 的 IO 开销从测量中彻底剔除保证结果聚焦于 Logger 管线与 LogContext 富化本身。注意一个细节Bare用的是未配置 FromLogContext 的 logger写预构造事件所以它的 14.59 ns 只代表事件已构造完毕的最短路径不含模板解析与属性绑定。解读时不要把这条基线误当成真实业务日志的完整耗时。三、为什么 PushProperty 这么贵从源码看完整调用链LogContext.PushProperty的入口在 LogContext.cs其实现只是把调用转发给Push(new PropertyEnricher(name, value, destructureObjects))。一次压栈的完整流程构造PropertyEnricherPropertyEnricherCore/Enrichers/PropertyEnricher.cs构造时立即调用LogEventProperty.EnsureValidName(name)做属性名合法性校验并保存名称、值、destructureObjects标志。取或建当前上下文栈GetOrCreateEnricherStack()从AsyncLocalEnricherStack?读取当前栈为 null 时替换为EnricherStack.Empty。这是整条路径上唯一一次有则读、无则建的懒初始化。不可变链式压栈EnricherStack.Push返回一个新栈节点_under指向上一个节点_top指向新 enricherCount under.Count 1而不修改原节点——这是典型函数式数据结构见 EnricherStack.cs。写回AsyncLocal并返回书签Enrichers stack更新当前逻辑执行上下文同时构造ContextStackBookmark保存压栈前的栈引用作为撤销点。作用域退出时弹出bookmark.Dispose()执行Enrichers _bookmark把AsyncLocal一步还原到压栈前的状态——注意弹栈是O(1) 整段回退不需要逐节点删除。成本来源可以归纳为三块AsyncLocalT写入每次压栈/弹栈都要写Data.Value.NET Framework 4.x 上的 AsyncLocal 访问比裸字段读写慢一个量级这正是跨 async/await 保真所需的代价。不可变栈节点分配每次 Push 分配一个新EnricherStack节点嵌套越深分配越多GC 压力随之上升。PropertyEnricher与属性名校验每压一个属性就要构造一个 enricher 并做名称校验。这也解释了基准的线性趋势PushProperty385 ns vsPushPropertyNested779 ns两次压栈几乎是单次的严格两倍385 × 2 ≈ 770说明压栈本身是近似线性的、无超线性退化。四、上下文如何注入日志事件FromLogContext 的幕后真正把上下文属性搬到事件上的是配置环节的.Enrich.FromLogContext()。它定义在 LoggerEnrichmentConfiguration.cspublic LoggerConfiguration FromLogContext() WithLogContextEnricher();WithTEnricher()会实例化LogContextEnricherContext/LogContextEnricher.cs它是一个极薄的信使sealed class LogContextEnricher : ILogEventEnricher { public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { LogContext.Enrich(logEvent, propertyFactory); } }当一条日志写入时事件流经 Logger.cs 的PostLevelCheckEmit先调用_enricher.Enrich(logEvent, _messageTemplateProcessor)再_sink.Emit(logEvent)。LogContext.EnrichLogContext.cs会遍历当前EnricherStack上的所有 enricher逐个调用其Enrich栈为空时直接短路返回零富化开销。最终每个PropertyEnricher.Enrich调用logEvent.AddPropertyIfAbsent(...)写入事件的属性字典。关键语义在 Events/LogEvent.cs只在属性名不存在时才添加——即后来的同名属性不会覆盖先写入的属性而上下文属性是在事件主体属性之后才注入的所以压栈顺序靠后更内层的属性先被添加反而优先保留。这一点由测试MoreNestedPropertiesOverrideLessNestedOnesLogContextTests.cs直接验证内层PushProperty(A, 2)生效期间事件中A 2退出内层作用域后恢复A 1全部退出后事件不再包含A。值得注意若LogContext.Enrich内部抛异常PostLevelCheckEmit的 try/catch 会把异常写入SelfLog并继续向 sink 派发Logger.cs富化失败不会阻断日志写入——这是日志库的容错惯例。五、嵌套压栈与同名覆盖语义比性能更重要基准里的PushPropertyNested不只测成本还隐含一个高频使用模式用嵌套using表达作用域层级。测试 LogContextTests.cs 进一步验证了多层同名覆盖外层Push(A11, A22)、内层Push(A110, A220)事件中同时存在A110与A220退出内层作用域后回到A11, A22全部退出后A1、A2均消失。这带来两个实践准则内层作用域叠加而非清空压栈是推叠式内层属性会补充外层属性不存在的键会被补上、同名的键被内层值占据。弹栈是整段回退Dispose把AsyncLocal还原到书签记录点因此内层作用域退出后外层属性原样恢复无需手动移除属性。六、成本边界与优化指引该省什么、不该省什么6.1 别让 PushProperty 成为每行日志的标配从基准看一次压栈385 ns比一次事件写入14.6 ns贵 26 倍。当PushProperty被放在每条日志的外层时等于给每条日志额外叠加约 385 ns 的固定成本。更划算的替代方案作用域化推送把 PushProperty 提升到请求/事务作用域的外层让多个日志共享一份上下文开销摊薄单条成本。配置期静态富化对始终不变的属性如服务名、实例 ID用.Enrich.WithProperty(name, value)LoggerEnrichmentConfiguration.cs在日志器构造时绑定走FixedPropertyEnricher路径完全避开每次的 AsyncLocal 读写。惰性条件富化.Enrich.When(...)/.Enrich.AtLevel(LogEventLevel.Warning, ...)可让昂贵富化只在满足条件如级别足够高时执行见 LoggerEnrichmentConfiguration.cs。6.2 FromLogContext 在空栈时是廉价的LogContext.Enrich在Enrichers null || Enrichers EnricherStack.Empty时直接 returnLogContext.cs。因此已配置.Enrich.FromLogContext()但当前没有压任何属性的 logger其富化路径近乎零成本不必担心开个开关就拖垮性能。6.3 富化失败不影响日志写入PostLevelCheckEmit与 SafeAggregateEnricher.cs 都采用异常入 SelfLog、继续派发的策略上下文富化是尽力而为的增强不是写入的前置依赖。七、跨平台对照.NET Core 上成本显著下降仓库results/目录还保留了同一基准在 .NET Core 上的历史报告可用于观察运行时差异注意其 BenchmarkDotNet 与硬件不同仅作定性对照勿与 net4.5.2 数值直接比大小results/netcoreapp2.0/LogContextEnrichmentBenchmark-report-github.mdBare 12.05 nsPushProperty 149.67 ns约 12.4 倍PushPropertyNested 296.44 ns约 24.7 倍PushPropertyEnriched 304.18 ns约 25.3 倍。results/netcoreapp1.0/LogContextEnrichmentBenchmark-report-github.md 与 results/netcoreapp1.1/LogContextEnrichmentBenchmark-report-github.md 亦有同期数据。趋势非常清晰同样的压栈操作在 .NET Core现代 CoreCLR上绝对值与相对倍数都大幅低于 .NET Framework 4.x。这与 AsyncLocal 等基础原语在新运行时的实现优化直接相关——如果你正在做性能敏感服务的上下文富化运行时的选择本身就是最重要的优化项之一。八、基准如何复跑PerformanceTests 项目基准源码位于 test/Serilog.PerformanceTests/LogContextEnrichmentBenchmark.cs项目使用 xUnit 托管 BenchmarkDotNetv0.15.2声明为[MemoryDiagnoser]附带内存分配统计。有三种复跑方式xUnit 筛选dotnet test -c Release --filter FullyQualifiedNameSerilog.PerformanceTests.Harness.LogContextEnrichment——Harness类test/Serilog.PerformanceTests/Harness.cs以[Fact]形式调BenchmarkRunner.RunLogContextEnrichmentBenchmark()dotnet test即可触发完整基准。批量脚本仓库根目录的 RunPerfTests.ps1 先执行Build.ps1再对每个test/*.PerformanceTests项目运行dotnet test -c Release。BenchmarkDotNet 独立运行直接把基准类作为入口运行BenchmarkDotNet 会输出标准报告其格式即本仓库results/目录中报告文件的来源。提示基准应在Release配置、无调试器附加、尽量空闲的机器上运行单次吞吐量数值受 CPU 频率、GC 模式与并发影响跨机器对比时请优先看Scaled 相对倍数而非绝对值。九、进阶Clone、Suspend、Reset 与异步作用域LogContext除PushProperty外还提供几个用于管理作用域的高级 APILogContext.csClone()返回SafeAggregateEnricher封装当前栈快照可在别的线程/位置重新Push回去。测试LogContextCanBeCloned与ClonedLogContextCanSharedAcrossThreadsLogContextTests.cs验证了跨线程复用的正确性。Suspend()将当前栈替换为空栈返回书签Dispose时恢复。测试ContextEnrichersCanBeTemporarilyCleared验证作用域内无富化、作用域外恢复。Reset()清空当前异步作用域的栈不影响外部作用域典型场景是在Task.Run内做隔离见测试ContextEnrichersInAsyncScopeCanBeClearedLogContextTests.cs。底层AsyncLocalEnricherStack?意味着作用域是逻辑执行上下文而非线程栈ContextPropertiesCrossAsyncCalls测试LogContextTests.cs用Task.Yield()强制切换线程后属性依然可见——这正是 ASP.NET Core 请求处理这类异步链路中压一个 RequestId、全程可查能力的来源。十、小结一份基准报告的工程启示回到这份 net4.5.2 基准报告最值得带走的四点压栈是相对昂贵但确定的操作单次约 385 ns、裸写入约 14.6 ns嵌套线性叠加无常量级突变这主要来自 AsyncLocal 写回与不可变栈节点分配。富化写入是顺路的PushPropertyEnriched约 598 ns≈ 压栈385 ns 富化写入约 213 ns相比裸写入多出的大部分成本集中在压栈本身。运行时是最大变量同一基准在 .NET Core 上相对倍数从 26.6 倍降到约 12.4 倍升级运行时能直接压缩上下文富化的开销。语义正确性优先嵌套覆盖、跨 async/await 传播、Clone/Suspend/Reset 的作用域控制都有 LogContextTests.cs 的完整测试背书——性能优化务必在语义正确的前提下进行。如果你的服务大量使用LogContext.PushProperty注入上下文建议结合上述源码路径LogContext.cs、EnricherStack.cs、LogEvent.cs重新审视哪些属性可以提升到更外层作用域、哪些可以改为配置期静态富化从而在保留结构化日志可追溯性的同时把每条日志的富化成本压到最低。赞分享后端可观测性【免费下载链接】serilogSimple .NET logging with fully-structured events项目地址https://gitcode.com/gh_mirrors/se/serilog点击查看免费下载相关推荐在 xrpld 开发中使用 Nix 开发环境可复现工具链、编译器选择与 CI 对齐的完整指南在 xrpld 开发中使用 Nix 开发环境可复现工具链、编译器选择与 CI 对齐的完整指南 本篇指南面向 rippledxrpld的贡献者与开发者系统后端可观测性Serilog性能基准NestedLoggerCreationBenchmark结果解读Serilog性能基准NestedLoggerCreationBenchmark结果解读 在.NET应用程序开发中日志记录是不可或缺的环节但日志组件的性能后端可观测性用 rkt-monitor 实测 Pod 级资源开销rkt 性能基准工具的原理与实操用 rkt monitor 实测 Pod 级资源开销rkt 性能基准工具的原理与实操 rkt monitor 是 rkt 仓库内置的一个小型 Go 基准测试工容器运行时云原生网络创作声明：本文部分内容由AI辅助生成（AIGC），仅供参考