Entity Framework Core 中的日志记录与拦截器

Posted JimCarter

tags:

篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了Entity Framework Core 中的日志记录与拦截器相关的知识，希望对你有一定的参考价值。

https://docs.microsoft.com/zh-cn/ef/core/logging-events-diagnostics/

文章目录

1.机制

efcore包含一些用于生成日志、响应时间和或者诊断结果的机制。具体见下表：

机制名称支持异步范围进行配置的位置用途
简单的日志记录否上下文数据库上下文开发时日志记录
Microsoft.Extensions.Logging否上下文DI或数据库上下文生产日志记录
事件否上下文任何位置对 EF 事件做出反应
拦截器是上下文数据库上下文进行 EF 操作
诊断侦听器否进程全局应用程序诊断

2. 简单的日志记录

直接在OnConfiguring里配置LogTo即可：

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)

    optionsBuilder.LogTo(Console.WriteLine);
    //或
    optionsBuilder.LogTo(msg=>Console.WriteLine(msg));

2.1 日志的详细信息

默认efcore不会将数据的值包含在异常消息中，因为这类数据可能是敏感的。但是在调试时如果能够看到这些值将是非常非常有用的，通过EnableSensitiveDataLogging()启用此功能:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine)
        .EnableSensitiveDataLogging();

出于性能方面的考虑，efcore不会将每一次对数据库的调用都用try-catch包裹起来。但这样有时候遇到问题时会很难诊断，特别是当数据库返回null值而模型却不允许null的时候。可以使用EnableDetailedErrors方法，让efcore返回具体的错误信息：

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine)
        .EnableDetailedErrors();

2.2 日志过滤

  1. 通过LogTo的第二个参数控制日志级别：
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(Console.WriteLine, LogLevel.Information);
  1. 将EventId（可从 CoreEventId 类或 RelationalEventId 类获取）传入LogTo的第二个参数，以输出指定类型的日志：
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine, new[]  CoreEventId.ContextDisposed, CoreEventId.ContextInitialized );
  1. 也可以根据消息的类别进行过滤

每条日志消息都分配到一个命名的分层记录器类别。 类别为：

类别说明
Microsoft.EntityFrameworkCore所有 EF Core 消息
Microsoft.EntityFrameworkCore.Database所有数据库交互
Microsoft.EntityFrameworkCore.Database.Connection使用数据库连接
Microsoft.EntityFrameworkCore.Database.Command 使用数据库命令
Microsoft.EntityFrameworkCore.Database.Transaction使用数据库事务
Microsoft.EntityFrameworkCore.Update保存实体，排除数据库交互
Microsoft.EntityFrameworkCore.Model所有模型和元数据交互
Microsoft.EntityFrameworkCore.Model.Validation模型验证
Microsoft.EntityFrameworkCore.Query查询，排除数据库交互
Microsoft.EntityFrameworkCore.Infrastructure常规事件，例如上下文创建
Microsoft.EntityFrameworkCore.Scaffolding数据库反向工程
Microsoft.EntityFrameworkCore.Migrations迁移
Microsoft.EntityFrameworkCore.ChangeTracking更改跟踪交互

比如记录数据库交互的日志：

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine, new[]  DbLoggerCategory.Database.Name );
  1. 自定义过滤器
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(
            Console.WriteLine,
            (eventId, logLevel) => logLevel >= LogLevel.Information
                                   || eventId == RelationalEventId.ConnectionOpened
                                   || eventId == RelationalEventId.ConnectionClosed);

2.3 设置日志的内容和格式

默认日志内容是多行显示，第一行包括Loglevel、本地时间、EventId、消息类别，第二行是具体内容：

info: 10/6/2020 10:52:45.581 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      CREATE TABLE "Blogs" (
          "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,
          "Name" INTEGER NOT NULL
      );
dbug: 10/6/2020 10:52:45.582 RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committing transaction.
dbug: 10/6/2020 10:52:45.585 RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committed transaction.

设置DbContextLoggerOptions.DefaultWithUtcTime使用UTC时间和单行显示

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(
        Console.WriteLine,
        LogLevel.Debug,
        DbContextLoggerOptions.UtcTime | DbContextLoggerOptions.SingleLine);

3. 使用Microsoft.Extensions.Logging

默认已支持

4. 事件

efcore包含有以下几个事件

事件引入的efcore版本触发时间
DbContext.SavingChanges5.0在调用SaveChanges或SaveChangesAsync前
DbContext.SavedChanges5.0成功调用SaveChanges 或 SaveChangesAsync之后
DbContext.SaveChangesFailed5.0调用SaveChanges 或 SaveChangesAsync失败时
ChangeTracker.Tracked2.1context首次跟踪实体后
ChangeTracker.StateChanged2.1当被跟踪的实体更改其状态时（首次进行跟踪时不会触发）

示例：

public interface IHasTimestamps

    DateTime? Added  get; set; 
    DateTime? Deleted  get; set; 
    DateTime? Modified  get; set; 

public BlogsContext()

    ChangeTracker.StateChanged += UpdateTimestamps;
    ChangeTracker.Tracked += UpdateTimestamps;


private static void UpdateTimestamps(object sender, EntityEntryEventArgs e)

    if (e.Entry.Entity is IHasTimestamps entityWithTimestamps)
    
        switch (e.Entry.State)
        
            case EntityState.Deleted:
                entityWithTimestamps.Deleted = DateTime.UtcNow;
                Console.WriteLine($"Stamped for delete: e.Entry.Entity");
                break;
            case EntityState.Modified:
                entityWithTimestamps.Modified = DateTime.UtcNow;
                Console.WriteLine($"Stamped for update: e.Entry.Entity");
                break;
            case EntityState.Added:
                entityWithTimestamps.Added = DateTime.UtcNow;
                Console.WriteLine($"Stamped for insert: e.Entry.Entity");
                break;

5. 拦截器

可以拦截、修改、禁止efcore的操作。包括低级的数据库操作（如执行命令）和高级的数据库操作（如对SaveChanges的调用）。

5.1 注册拦截器

在OnConfiguring里进行配置

public class ExampleContext : BlogsContext

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        => optionsBuilder.AddInterceptors(new TaggedQueryCommandInterceptor());

5.2 实现数据库拦截器

低级别的数据库拦截涉及到三个接口：

接口efcore自带实现基类已截获数据库操作
IDbCommandInterceptorDbCommandInterceptor创建命令 执行命令 执行失败
IDbConnectionInterceptorDbConnectionInterceptor打开/关闭连接 连接失败
IDbTransactionInterceptorDbTransactionInterceptor创建事务 提交事务 回退事务 创建和使用保存点 事务失败

然后使用TagWith方法对查询进行标记：

var blogs1 = context.Blogs.TagWith("Use hint: robust plan").ToList();

创建上面的TaggedQueryCommandInterceptor拦截器：

public class TaggedQueryCommandInterceptor : DbCommandInterceptor

    public override InterceptionResult<DbDataReader> ReaderExecuting(DbCommand command,CommandEventData eventData,InterceptionResult<DbDataReader> result)
    
        ManipulateCommand(command);
        return result;
    

    public override ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command,CommandEventData eventData,InterceptionResult<DbDataReader> result,CancellationToken cancellationToken = default)
    
        ManipulateCommand(command);
        return new ValueTask<InterceptionResult<DbDataReader>>(result);
    

    private static void ManipulateCommand(DbCommand command)
    
        if (command.CommandText.StartsWith("-- Use hint: robust plan", StringComparison.Ordinal))
        
            command.CommandText += " OPTION (ROBUST PLAN)";

拦截器同时实现了同步和异步的方法，可应用到同步或异步查询中。此时生成的sql如下：

-- Use hint: robust plan

SELECT [b].[Id], [b].[Name]
FROM [Blogs] AS [b] OPTION (ROBUST PLAN)

5.2.1 示例

需要实现的功能：当查询前先查下缓存，如有有缓存则直接返回。否则将从数据库查询出来的数据存放到缓存中。

以下示例用来获取最新的每天消息：

  1. 首先给查询打tag：
async Task<string> GetDailyMessage(DailyMessageContext context)
    => (await context.DailyMessages.TagWith("Get_Daily_Message").OrderBy(e => e.Id).LastAsync()).Message;
  1. 设置拦截器需要的一些参数
public class CachingCommandInterceptor : DbCommandInterceptor

    private readonly object _lock = new object();
    private int _id;
    private string _message;
    private DateTime _queriedAt;
    
    public override ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command,CommandEventData eventData,InterceptionResult<DbDataReader> result,CancellationToken cancellationToken = default)
    
       //...
    

    public override async ValueTask<DbDataReader> ReaderExecutedAsync(DbCommand command,CommandExecutedEventData eventData,DbDataReader result,CancellationToken cancellationToken = default)
    
        //...

因为拦截器是全局的而且可以应用到多个dbcotext上，所以需要定义一个锁。
3. 在数据库查询执行之前，拦截器根据之前打的tag来定位具体的查询，然后检查是否有缓存

public override ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command,CommandEventData eventData,InterceptionResult<DbDataReader> result,CancellationToken cancellationToken = default)

    if (command.CommandText.StartsWith("-- Get_Daily_Message", StringComparison.Ordinal))
    
        lock (_lock)
        
            if (_message != null&& DateTime.UtcNow < _queriedAt + new TimeSpan(0, 0, 10))//查询10s以内的数据
            
                //因为sql不会到数据库执行，所以可以加一些自定义的注释
                command.CommandText = "-- Get_Daily_Message: Skipping DB call; using cache.";
                result = InterceptionResult<DbDataReader>.SuppressWithResult(new CachedDailyMessageDataReader(_id, _message));
            
        
    

    return new ValueTask<InterceptionResult<DbDataReader>>(result);
  1. 如果没有发现缓存则会执行到ReaderExecutedAsync方法
public override async ValueTask<DbDataReader> ReaderExecutedAsync(DbCommand command,CommandExecutedEventData eventData,DbDataReader result,CancellationToken cancellationToken = default)

    if (command.CommandText.StartsWith("-- Get_Daily_Message", StringComparison.Ordinal)&& !(result is CachedDailyMessageDataReader))
    
        try
        
            await result.ReadAsync(cancellationToken);
            lock (_lock)
            
                _id = result.GetInt32(0);
                _message = result.GetString(1);
                _queriedAt = DateTime.UtcNow;
                return new CachedDailyMessageDataReader(_id, _message);
            
        
        finally
        
            await result.DisposeAsync();
        
    

    return result;

5.3 对OnSaveChanges的拦截

应用场景：记录某些人对数据做了哪些更改时。

实现方法：有两个数据库上下文，用户对BlogsContext进行更改操作，并配置拦截。AuditContext存储用户的具体操作。

  1. 首先配置BlogsContext
public class BlogsContext : DbContext

    private readonly AuditingInterceptor _auditingInterceptor = new AuditingInterceptor("DataSource=audit.db");
    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        => optionsBuilder
            .AddInterceptors(_auditingInterceptor)
            .UseSqlite("DataSource=blogs.db");
    public DbSet<Blog> Blogs  get; set;

主要是配置拦截器
2. AuditContext无须额外设置

public class AuditContext : DbContext

    private readonly string _connectionString;

    public AuditContext(string connectionString)
    
        _connectionString = connectionString;
    

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        => optionsBuilder.UseSqlite(_connectionString);

    public DbSet<SaveChangesAudit> SaveChangesAudits  get; set; 


public class SaveChangesAudit

    public int Id  get; set; 
    public Guid AuditId  get; set; 
    public DateTime StartTime  get; set; 
    public DateTime EndTime  get; set; 
    public bool Succeeded  get; set; 
    public string ErrorMessage  get; set; 

    public ICollection<EntityAudit> Entities  get;  = new List<EntityAudit>();


public class EntityAudit

    public int Id  get; set; 
    public EntityState State  get; set; 
    public string AuditMessage  get; set; 

    public SaveChangesAudit SaveChangesAudit  get; set;
  1. AuditingInterceptor的实现逻辑
    在SaveChanges时就记录数据，并写入数据库。如果保存失败，则记录操作失败。如果保存成功，则记录操作成功。

实现ISaveChangesInterceptor接口，实现SavingChangesAsync、SavedChangesAsync、SaveChangesFailedAsync三个异步方法和对应的同步方法。

//保存时
public async ValueTask<InterceptionResult<int>> SavingChangesAsync(
    DbContextEventData eventData,
    InterceptionResult<int> result,
    CancellationToken cancellationToken = default)

    _audit = CreateAudit(eventData.Context);

    using (var auditContext = new AuditContext(_connectionString))
    
        auditContext.Add(_audit);
        await auditContext.SaveChangesAsync();
    

    return result;

//保存成功时
public async ValueTask<int> SavedChangesAsync(
    SaveChangesCompletedEventData eventData,
    int result,
    CancellationToken cancellationToken = default)

    using (var auditContext = new AuditContext(_connectionString))
    
        auditContext.Attach(_audit);
        _audit.Succeeded = true;
        _audit.EndTime = DateTime.UtcNow;

        await auditContext.SaveChangesAsync(cancellationToken);
    

    return result;

//保存失败时
public async Task SaveChangesFailedAsync(
    DbContextErrorEventData eventData,
    CancellationToken cancellationToken = default)

    using (var auditContext = new AuditContext(_connectionString))
    
        auditContext.Attach(_audit);
        _audit.Succeeded = false;
        _audit.EndTime = DateTime.UtcNow;
        _audit.ErrorMessage = eventData.Exception.InnerException?.Message;

        await auditContext.SaveChangesAsync(cancellationToken);
    以上是关于Entity Framework Core 中的日志记录与拦截器的主要内容，如果未能解决你的问题，请参考以下文章
 

 Entity Framework Core 2 中的 ConnectionString 生成器


 根据 ASP.NET Core 和 Entity Framework Core 中的条件禁用 [必需] 属性


 Entity Framework Core 中的动态数据模型


 Entity Framework Core 中的动态查询执行


 无法更新 Entity Framework Core 中的标识列


 ASP.NET Core 和 Entity Framework Core：Linq 中的左（外）连接