启用调试日志级别时，Serilog 会严重影响性能

Question

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

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

我们的项目使用：

这是 Serilog 所期望的那种性能吗？

编辑：我在另一个（远）较小的项目中注意到了相同的行为。这使我能够隔离问题：我有一个正在检索 ProcessId 的自定义丰富器。打电话Process.GetCurrentProcess()是非常昂贵的。对每个日志记录调用都这样做会导致性能下降。我将进程 ID 存储在实例字段中，性能飙升。

Answer 1

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

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

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

也就是说，这并不是 Serilog 速度慢，而是您的应用程序无意中让它做了很多无用的工作。

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

从长远来看，审核调试级别日志记录以使用非常量消息模板、@和destructureObjects: true应该有助于使事情恢复到正常水平。