如何在Entity Framework Core中记录运行超1秒的慢查询

刚好我之前在EF Core 2.1项目里落地过类似的慢查询日志需求，给你分享下经过验证的最优实现方案，全程贴合2.1版本的特性：

核心思路 #

EF Core 2.1没有后续版本的DbCommandInterceptor特性，所以我们通过订阅EF的诊断事件来捕获命令执行的全生命周期，计算耗时后筛选出超过1秒的查询，再用Serilog记录SQL语句、参数和耗时。

步骤1：编写慢查询监听类 #

这个类会订阅EF发布的命令执行事件，自动计算耗时并过滤慢查询：

using System;
using System.Collections.Generic;
using System.Data.Common;
using System.Linq;
using Microsoft.EntityFrameworkCore.Diagnostics;
using Microsoft.Extensions.Logging;
using System.Diagnostics;

public class EFSlowQueryLogger
{
    private readonly ILogger<EFSlowQueryLogger> _logger;
    private readonly Dictionary<Guid, DateTimeOffset> _commandStartTimeTracker = new();

    public EFSlowQueryLogger(ILogger<EFSlowQueryLogger> logger)
    {
        _logger = logger;
    }

    public void StartListening()
    {
        // 订阅所有EF Core的诊断事件
        DiagnosticListener.AllListeners.Subscribe(listener =>
        {
            if (listener.Name.Equals("Microsoft.EntityFrameworkCore", StringComparison.Ordinal))
            {
                listener.SubscribeWithAdapter(this);
            }
        });
    }

    // 捕获命令开始执行的事件
    [DiagnosticName("Microsoft.EntityFrameworkCore.Database.Command.CommandExecuting")]
    public void OnCommandExecuting(DbCommand command, Guid commandId, Guid connectionId, bool async, DateTimeOffset startTime)
    {
        _commandStartTimeTracker[commandId] = startTime;
    }

    // 捕获命令执行完成的事件
    [DiagnosticName("Microsoft.EntityFrameworkCore.Database.Command.CommandExecuted")]
    public void OnCommandExecuted(DbCommand command, Guid commandId, Guid connectionId, bool async, DateTimeOffset startTime, DateTimeOffset endTime)
    {
        if (_commandStartTimeTracker.TryRemove(commandId, out var actualStartTime))
        {
            var elapsedMs = (endTime - actualStartTime).TotalMilliseconds;
            if (elapsedMs > 1000) // 筛选超过1秒的查询
            {
                // 格式化参数输出，方便排查问题
                var parameters = string.Join(", ", command.Parameters.Cast<DbParameter>()
                    .Select(p => $"{p.ParameterName}={p.Value ?? "NULL"}"));

                // 用Serilog记录慢查询详情
                _logger.Information(
                    "⚠️ Slow EF Query Detected | Elapsed: {ElapsedMs:F2}ms | SQL: {Sql} | Parameters: {Parameters}",
                    elapsedMs,
                    command.CommandText,
                    parameters);
            }
        }
    }

    // 捕获命令执行失败的事件，清理追踪记录
    [DiagnosticName("Microsoft.EntityFrameworkCore.Database.Command.CommandFailed")]
    public void OnCommandFailed(DbCommand command, Guid commandId, Guid connectionId, bool async, DateTimeOffset startTime, Exception exception)
    {
        _commandStartTimeTracker.TryRemove(commandId, out _);
    }
}

步骤2：注册并启动监听 #

在Startup.cs里完成服务注册和监听启动：

public void ConfigureServices(IServiceCollection services)
{
    // 注册EF上下文（记得替换成你的DbContext）
    services.AddDbContext<YourDbContext>(options =>
    {
        options.UseSqlServer(Configuration.GetConnectionString("YourConnectionString"))
               .EnableSensitiveDataLogging(); // 可选：开启后会记录参数的真实值，生产环境需谨慎
    });

    // 注册慢查询监听类为单例
    services.AddSingleton<EFSlowQueryLogger>();
}

public void Configure(IApplicationBuilder app, IWebHostEnvironment env, EFSlowQueryLogger slowQueryLogger)
{
    // ...其他中间件配置（比如路由、静态文件等）
    
    // 启动EF慢查询监听
    slowQueryLogger.StartListening();
}

步骤3：配置Serilog输出 #

确保Serilog的配置能正确输出我们的慢查询日志，比如在appsettings.json中：

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft": "Warning",
        "System": "Warning"
      }
    },
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"
        }
      },
      {
        "Name": "File",
        "Args": {
          "path": "logs/slow-ef-queries-.txt",
          "rollingInterval": "Day",
          "outputTemplate": "[{Timestamp:yyyy-MM-dd HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"
        }
      }
    ]
  }
}

关键注意事项 #

• 敏感数据风险：EnableSensitiveDataLogging()会记录参数的真实值，比如用户密码、手机号等，生产环境建议关闭，或者配合Serilog的字段过滤规则隐藏敏感信息。
• 性能开销：订阅诊断事件的性能损耗极低，且我们只记录超过1秒的查询，对系统整体性能几乎无影响。
• 日志可读性：如果SQL语句太长，可以考虑在Serilog配置中开启换行，或者用结构化日志工具（比如Seq）来更友好地查看。

内容的提问来源于stack exchange，提问作者Jim Culverwell