Serilog 异步 CPU 使用率高达 100%

Posted 2023-03-07

【中文标题】Serilog 异步 CPU 使用率高达 100%

【英文标题】：Serilog async high CPU usage upto 100%

【发布时间】：2021-01-15 16:36:33

【问题描述】：

我使用 Serilog 异步日志记录，在对多个用户进行性能测试时，我们发现 serilog 占用了所有 CPU（高达 100%）。 ASP.net 代码使用 Serilog Async（log.info、log.warning、log.error）创建日志文件，并且由于安全日志记录要求，它在所有网页上都有日志记录。 CPU 使用率在 2 小时后达到峰值，并且持续保持 100%，系统性能受到严重影响。

我们还测试了未启用 SeriLog 的应用程序，该应用程序的 CPU 使用率不会达到 100%。

如果我能在这里得到任何帮助，我将不胜感激。如果需要，我可以共享我创建的代码（记录器类）。

以及如何配置日志记录：

var logConfig = new LoggerConfiguration()
            .MinimumLevel.Information()
            .WriteTo.Async(logSink =>
            
                logSink.File(
                    logFilePath,
                    rollingInterval: RollingInterval.Day,
                    retainedFileCountLimit: null,
                    outputTemplate: OutputTemplate,
                    hooks: new HeaderWriter(header),
                    flushToDiskInterval: TimeSpan.FromSeconds(10),
                    shared: true
                    );
            );
        Log.Logger = logConfig.CreateLogger();

【问题讨论】：

您能分享您的记录器配置吗？我还建议查看 serilog 的 SelfLog。是否有任何错误消息？

@Tolyandre 感谢您的输入。我已按要求将配置添加到帖子中。

“我们还测试了没有 Serilog 登录文件的应用程序，系统正在运行完整的文件，没有 CPU 峰值，因此它必须使用 Serilog 异步进行一些操作。”这甚至意味着什么？

@IanKemp 我的意思是当 SeriLog 被禁用时，应用程序的 CPU 使用率不会达到 100%。

@IanKemp 这是从少量输入中得出的大量推论；）异步接收器不会以这种方式诱导并行性

【参考方案1】：

关于进一步研究 Serilog 性能的一些想法：

查看SelfLog 中是否有任何消息。通常 SelfLog 是空的。如果有，请修复它们。

Serilog.Debugging.SelfLog.Enable(Console.Error);

Serilog 解析和缓存每个模板（达到固定大小限制）https://github.com/serilog/serilog/wiki/Writing-Log-Events#message-template-recommendations。 日志模板比可变消息更好：

// Don't:
Log.Information("The time is " + DateTime.Now);

// Do:
Log.Information("The time is Now", DateTime.Now);

如果您记录大字符串，请将它们记录为属性以防止解析和缓存。

不要意外破坏具有不适当属性的对象：

Task、Stream 等类型 做很多工作的财产获取者 抛出的属性获取器

// Don't

// Destructuring entire Request with @ will generate a lot of useless data
Log.Information("Got request @HttpRequest", HttpContext.Request);

如果要记录此类复杂对象，请定义 Destructure.ByTransforming() 或 IDestructuringPolicy。