启用调试日志级别时，Serilog 性能大幅下降

Question

我在 .NET Core Service Fabric 应用程序上使用 Serilog。
我们注意到性能问题，经过调查发现 Serilog 是罪魁祸首。

我们记录了约 2,000 条调试消息，这需要 10 多秒。
即使仅配置了控制台接收器并将其设置为仅在信息日志级别进行过滤（因此不显示任何调试消息）也是如此。
将 MinimumLevel 设置为 Information 会使相同的代码运行 <1 秒（即使配置了接收器）。

我们的项目使用：

netcoreapp2.0
Serilog NuGet 包 2.8.0（最新）

这是 Serilog 所期望的性能吗？

编辑：我注意到另一个（更）小的项目有同样的行为。这让我能够隔离问题：我有一个自定义的 enricher 正在检索 ProcessId。调用 Process.GetCurrentProcess() 非常昂贵。对每个日志记录调用都这样做会降低性能。我把进程Id存到一个实例字段里，性能飙升

Answer 1

过滤掉调试级别的事件与设置最低级别不同； Serilog 可用于结构化日志数据的序列化，因此 Debug 事件的构建很可能会占用时间。

这可能表明您的调试日志记录存在问题 - Serilog 本身很快，但如果您的调试事件正在序列化任意大的东西，例如request/response 有效负载或 DTO，您的应用程序最终会进行大量反射，属性对对象的访问器调用（可能会阻塞、执行 I/O 和其他疯狂的事情）、分配和垃圾回收。

如果调试事件使用无效的消息模板（即通过使用 $"..." 字符串插值或非常量字符串进行记录），那么您的应用程序也会浪费大量精力将它们解析为格式字符串。

即这并不是说 Serilog 在这里很慢，而是您的应用程序无意中让它做了很多无用的工作。

使用 Debug 然后在控制台接收器上使用稍后的 Information 过滤器将导致所有这些工作完成，然后被丢弃。将最低级别设置为 Information 将阻止这项工作首先完成。

在漫长的运行中，审核您的调试级别日志记录以使用非常量消息模板，@ 和 destructureObjects: true 应该有助于将事情恢复到正常水平.

Answer 2

登录到控制台可能会使您的应用程序变慢。控制台日志记录是一种阻塞（同步）操作。使用 Serilog.Sinks.Async 缓冲日志调用并使用后台线程写入日志。

Log.Logger = new LoggerConfiguration()
.MinimumLevel.Information()
.WriteTo.Async(a => a.Console())
.CreateLogger()

如果需要记录调试信息，可以将其记录到文件中。我建议使用 restrictedToMinimumLevel 选项将控制台日志记录限制为信息。

new LoggerConfiguration()
.MinimumLevel.Debug()
.WriteTo.Async((wt) => 
{
   wt.File("log.txt");
   wt.Console(restrictedToMinimumLevel: LogEventLevel.Information);
}, bufferSize: 1000);

启用调试日志级别时，Serilog 性能大幅下降

Serilog massive performance hit when enabling Debug log level

serilog

.net-core