使用Serilog作为ILogger提供程序时LoggerMessage的内存分配问题

基准测试结果 #

相关配置与代码 #

appsettings.json配置 #

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Warning",
        "Microsoft.AspNetCore": "Warning",
        "System": "Warning"
      }
    }
  },
  "AllowedHosts": "*"
}

基准测试代码 #

[MemoryDiagnoser]
public class LoggingBenchmark
{
    private static ILogger<LoggingBenchmark> defaultLoggerWithSerilog;
    private static ApplicationLogger codeGenLoggerSerilog;

    private static ILogger<LoggingBenchmark> defaultLogger;
    private static ApplicationLogger codeGenLogger;

    private static Teste teste;

    [GlobalSetup]
    public void Init()
    {
        teste = new Teste();

        // Serilog 配置
        var configuration = new ConfigurationBuilder()
                .AddJsonFile(path: "appsettings.json", true, reloadOnChange: true)
                .Build();

        var sLogger = new LoggerConfiguration().ReadFrom.Configuration(configuration)
            .CreateLogger();

        var serilogLogger = new SerilogLoggerFactory(sLogger)
                .CreateLogger<LoggingBenchmark>();

        defaultLoggerWithSerilog = serilogLogger;
        codeGenLoggerSerilog = new ApplicationLogger(serilogLogger);

        // 默认日志提供器配置
        using var loggerFactory = LoggerFactory.Create(loggingBuilder => loggingBuilder
                .SetMinimumLevel(LogLevel.Trace));

        var logger = loggerFactory.CreateLogger<LoggingBenchmark>();

        defaultLogger = logger;
        codeGenLogger = new ApplicationLogger(logger);

    }

    [Benchmark]
    public void TestSerilog_Logger()
    {
        defaultLoggerWithSerilog.LogInformation("Teste {t}", teste);
    }

    [Benchmark]
    public void TestSerilog_CodeGenLogger()
    {
        codeGenLoggerSerilog.LogInformation(teste, "Teste");
    }

    [Benchmark]
    public void TestDefaultProvider_Logger()
    {
        defaultLogger.LogInformation("Teste {t}", teste);
    }

    [Benchmark]
    public void TestDefaultProvider_CodeGenLogger()
    {
        codeGenLogger.LogInformation(teste, "Teste");
    }

}

public class Teste
{
    public int Value { get; set; }
}

LoggerMessage相关代码 #

public void LogInformation<T>(T obj, string message, [CallerMemberName] string callerName = "", [CallerArgumentExpression("obj")] string objName = "") where T : notnull, new()
{
    LogInformation1CodeGen(_logger, callerName, message, obj, objName);
}

[LoggerMessage(
   Level = LogLevel.Information,
   Message = "Information in Method: {MethodName}, with Message {InformationMessage}, {objName}: {obj}")]
private static partial void LogInformation1CodeGen(ILogger logger, string methodName, string informationMessage, object obj, string objName);

问题 #

将Serilog作为ILogger<>提供程序时，LoggerMessage生成的日志方法相比普通LogInformation()存在明显的内存分配与性能差异，请问导致这种差异的原因是什么？

原因分析 #

• 装箱操作：LoggerMessage定义的LogInformation1CodeGen方法中，obj参数为object类型，调用时传入泛型T的实例（如Teste对象）会触发装箱，产生额外内存分配。而直接调用LogInformation时，Serilog的ILogger实现通过泛型重载避免了装箱。
• 参数结构与数量差异：LoggerMessage的日志模板包含4个参数（方法名、消息、对象名、对象），比直接调用的单参数模板复杂。Serilog处理多参数结构化日志时，需要创建更多事件属性结构，带来额外的内存开销和性能损耗。
• 第三方适配开销：LoggerMessage是针对ASP.NET Core默认日志提供器优化的特性，Serilog作为第三方实现，在处理LoggerMessage生成的调用时，需要进行额外的参数映射与转换，这个适配过程会产生额外的分配与性能开销。
• 泛型封装的间接调用：泛型方法LogInformation<T>对LoggerMessage部分方法的封装，增加了调用层级和泛型类型处理的少量开销，但并非主要原因。

内容的提问来源于stack exchange，提问作者Pedro Ferreira