记录和截取数据库操作Logging and intercepting database operations

备注

仅限 EF6 及更高版本 - 此页面中讨论的功能、API 等已引入实体框架 6。 如果使用的是早期版本，则部分或全部信息不适用。

从实体框架6开始，无论何时实体框架将命令发送到数据库，都可以通过应用程序代码截获此命令。 这通常用于记录 SQL，但也可用于修改或中止命令。

具体而言，EF 包括：

  • 与 DataContext 类似的上下文的日志属性。登录 LINQ to SQL
  • 用于自定义发送到日志的输出内容和格式的机制
  • 用于侦听的低级别构建基块，提供更好的控制/灵活性

Context 日志属性Context Log property

可以将 DbContext 属性设置为采用字符串的任何方法的委托。 最常见的情况是，通过将其设置为该该设置的 “Write” 方法，将其与任何未任何类型一起使用。 当前上下文生成的所有 SQL 都将记录到该编写器。 例如，以下代码将 SQL 日志记录到控制台：

  1. using (var context = new BlogContext())
  2. {
  3.     context.Database.Log = Console.Write;
  5.     // Your code here...
  6. }

请注意，上下文。数据库。日志设置为 Console。 这是将 SQL 日志记录到控制台所需的全部。

让我们添加一些简单的查询/插入/更新代码，以便我们可以看到一些输出：

  1. using (var context = new BlogContext())
  2. {
  3.     context.Database.Log = Console.Write;
  5.     var blog = context.Blogs.First(b => b.Title == "One Unicorn");
  7.     blog.Posts.First().Title = "Green Eggs and Ham";
  9.     blog.Posts.Add(new Post { Title = "I do not like them!" });
  11.     context.SaveChangesAsync().Wait();
  12. }

这将生成以下输出：

  1. SELECT TOP (1)
  2.     [Extent1].[Id] AS [Id],
  3.     [Extent1].[Title] AS [Title]
  4.     FROM [dbo].[Blogs] AS [Extent1]
  5.     WHERE (N'One Unicorn' = [Extent1].[Title]) AND ([Extent1].[Title] IS NOT NULL)
  6. -- Executing at 10/8/2013 10:55:41 AM -07:00
  7. -- Completed in 4 ms with result: SqlDataReader
  9. SELECT
  10.     [Extent1].[Id] AS [Id],
  11.     [Extent1].[Title] AS [Title],
  12.     [Extent1].[BlogId] AS [BlogId]
  13.     FROM [dbo].[Posts] AS [Extent1]
  14.     WHERE [Extent1].[BlogId] = @EntityKeyValue1
  15. -- EntityKeyValue1: '1' (Type = Int32)
  16. -- Executing at 10/8/2013 10:55:41 AM -07:00
  17. -- Completed in 2 ms with result: SqlDataReader
  19. UPDATE [dbo].[Posts]
  20. SET [Title] = @0
  21. WHERE ([Id] = @1)
  22. -- @0: 'Green Eggs and Ham' (Type = String, Size = -1)
  23. -- @1: '1' (Type = Int32)
  24. -- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
  25. -- Completed in 12 ms with result: 1
  27. INSERT [dbo].[Posts]([Title], [BlogId])
  28. VALUES (@0, @1)
  29. SELECT [Id]
  30. FROM [dbo].[Posts]
  31. WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()
  32. -- @0: 'I do not like them!' (Type = String, Size = -1)
  33. -- @1: '1' (Type = Int32)
  34. -- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
  35. -- Completed in 2 ms with result: SqlDataReader

（请注意，这是假设已发生任何数据库初始化的输出。 如果尚未发生数据库初始化，则会有更多的输出，显示所有工作迁移在这些情况下执行的操作，以检查或创建新数据库。）

记录了哪些内容？What gets logged?

设置日志属性后，将记录以下所有内容：

  • 适用于所有不同类型的命令的 SQL。 例如：
    • 查询，包括常规 LINQ 查询、eSQL 查询和来自 SqlQuery 等方法的原始查询
    • 作为 SaveChanges 的一部分生成的插入、更新和删除操作
    • 关系加载查询，如延迟加载生成的查询
  • 参数
  • 命令是否正在以异步方式执行
  • 指示命令开始执行的时间的时间戳
  • 命令是否已成功完成，引发异常，或是否已取消（对于异步）
  • 结果值的一些指示
  • 执行命令所花费的大致时间。 请注意，这是发送命令以返回结果对象的时间。 它不包含读取结果的时间。

查看上面的示例输出，记录的四个命令中的每一个都是：

  • 通过调用上下文产生的查询。博客。首先
    • 请注意，获取 SQL 的 ToString 方法不能处理此查询，因为 “First” 不提供可调用 ToString 的 IQueryable
  • 由博客的延迟加载引起的查询。创纪录
    • 请注意延迟加载发生的键值的参数详细信息
    • 仅记录设置为非默认值的参数的属性。 例如，仅当 Size 属性为非零时，才会显示该属性。
  • SaveChangesAsync 生成的两个命令;一项用于更改发布标题的更新，另一种用于添加新的帖子
    • 请注意 FK 和 Title 属性的参数详细信息
    • 请注意，这些命令是异步执行的

记录到不同的位置Logging to different places

如上所示，记录到控制台非常简单。 通过使用不同类型的类型，也可以很容易地记录到内存、文件等。

如果你熟悉 LINQ to SQL 你可能会注意到，在 LINQ to SQL 日志属性设置为实际的 “设置” 对象（例如，在 “控制台” 中），而在 EF 中，Log 属性被设置为接受字符串的方法（例如，Console. Write 或 Console。 这种情况的原因是，通过接受可充当字符串接收器的任何委托，将 EF 从无效中分离。 例如，假设已有一些日志记录框架，并定义如下所示的日志记录方法：

  1. public class MyLogger
  2. {
  3.     public void Log(string component, string message)
  4.     {
  5.         Console.WriteLine("Component: {0} Message: {1} ", component, message);
  6.     }
  7. }

此操作可能会挂接到 EF 日志属性，如下所示：

  1. var logger = new MyLogger();
  2. context.Database.Log = s => logger.Log("EFApp", s);

结果日志记录Result logging

默认情况下，在将命令发送到数据库之前，将使用时间戳来记录命令文本（SQL）、参数和 “执行” 行。 执行命令后，将记录包含运行时间的 “已完成” 行。

请注意，对于异步命令，在异步任务实际完成、失败或取消之前，不会记录 “已完成” 行。

“已完成” 行包含不同的信息，具体取决于命令的类型以及执行是否成功。

成功执行Successful execution

对于成功完成的命令，输出为 “在 x 毫秒内完成，结果为：”，后跟一些对结果的指示。 对于返回数据读取器的命令，结果指示是返回的DbDataReader的类型。 对于返回整数值的命令，如显示的结果上方显示的 update 命令，则为该整数。

执行失败Failed execution

对于通过引发异常而失败的命令，输出包含来自异常的消息。 例如，使用 SqlQuery 对存在的表进行查询时，会生成如下所示的日志输出：

  1. SELECT * from ThisTableIsMissing
  2. -- Executing at 5/13/2013 10:19:05 AM
  3. -- Failed in 1 ms with error: Invalid object name 'ThisTableIsMissing'.

已取消执行Canceled execution

对于取消任务的异步命令，结果可能会失败，并出现异常，因为这是当尝试取消时，基础 ADO.NET 提供程序经常执行的操作。 如果这种情况不会发生并且任务完全取消，则输出将如下所示：

  1. update Blogs set Title = 'No' where Id = -1
  2. -- Executing asynchronously at 5/13/2013 10:21:10 AM
  3. -- Canceled in 1 ms

更改日志内容和格式Changing log content and formatting

在 “数据库概述” 下，使用 DatabaseLogFormatter 对象。 此对象有效地将 IDbCommandInterceptor 实现（见下文）绑定到接受字符串和 DbContext 的委托。 这意味着，DatabaseLogFormatter 上的方法是在执行命令之前和之后调用的。 这些 DatabaseLogFormatter 方法收集并格式化日志输出，并将其发送到委托。

自定义 DatabaseLogFormatterCustomizing DatabaseLogFormatter

可以通过创建从 DatabaseLogFormatter 派生的新类并根据需要重写方法，从而更改所记录的内容和格式。 要重写的最常见方法是：

  • LogCommand –重写此方法以更改命令在执行之前的记录方式。 默认情况下，LogCommand 为每个参数调用 LogParameter;您可以选择在重写中执行相同的操作，或以不同的方式处理参数。
  • LogResult –重写此方法以更改如何记录执行命令的结果。
  • LogParameter –重写此参数以更改参数日志记录的格式和内容。

例如，假设我们想要在每个命令发送到数据库之前只记录一行。 可以通过两个替代来完成此操作：

  • 重写 LogCommand 以格式化和写入单一的 SQL 行
  • 重写 LogResult 不执行任何操作。

代码如下所示：

  1. public class OneLineFormatter : DatabaseLogFormatter
  2. {
  3.     public OneLineFormatter(DbContext context, Action<string> writeAction)
  4.         : base(context, writeAction)
  5.     {
  6.     }
  8.     public override void LogCommand<TResult>(
  9.         DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
  10.     {
  11.         Write(string.Format(
  12.             "Context '{0}' is executing command '{1}'{2}",
  13.             Context.GetType().Name,
  14.             command.CommandText.Replace(Environment.NewLine, ""),
  15.             Environment.NewLine));
  16.     }
  18.     public override void LogResult<TResult>(
  19.         DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
  20.     {
  21.     }
  22. }

若要日志输出，只需调用写入方法，该方法会将输出发送到配置的写入委托。

（请注意，此代码只是为了举例地删除换行符。 它在查看复杂的 SQL 时可能无法正常工作。）

设置 DatabaseLogFormatterSetting the DatabaseLogFormatter

创建新的 DatabaseLogFormatter 类后，需要将其注册到 EF。 这是使用基于代码的配置来完成的。 简而言之，这意味着要在与 DbContext 类相同的程序集中创建一个从 DbConfiguration 派生的新类，然后在此新类的构造函数中调用 SetDatabaseLogFormatter。 例如：

  1. public class MyDbConfiguration : DbConfiguration
  2. {
  3.     public MyDbConfiguration()
  4.     {
  5.         SetDatabaseLogFormatter(
  6.             (context, writeAction) => new OneLineFormatter(context, writeAction));
  7.     }
  8. }

使用新的 DatabaseLogFormatterUsing the new DatabaseLogFormatter

此新 DatabaseLogFormatter 将在每次设置数据库时使用。 因此，运行第1部分中的代码将生成以下输出：

  1. Context 'BlogContext' is executing command 'SELECT TOP (1) [Extent1].[Id] AS [Id], [Extent1].[Title] AS [Title]FROM [dbo].[Blogs] AS [Extent1]WHERE (N'One Unicorn' = [Extent1].[Title]) AND ([Extent1].[Title] IS NOT NULL)'
  2. Context 'BlogContext' is executing command 'SELECT [Extent1].[Id] AS [Id], [Extent1].[Title] AS [Title], [Extent1].[BlogId] AS [BlogId]FROM [dbo].[Posts] AS [Extent1]WHERE [Extent1].[BlogId] = @EntityKeyValue1'
  3. Context 'BlogContext' is executing command 'update [dbo].[Posts]set [Title] = @0where ([Id] = @1)'
  4. Context 'BlogContext' is executing command 'insert [dbo].[Posts]([Title], [BlogId])values (@0, @1)select [Id]from [dbo].[Posts]where @@rowcount > 0 and [Id] = scope_identity()'

拦截构建基块Interception building blocks

到目前为止，我们已经介绍了如何使用 DbContext 记录由 EF 生成的 SQL。 但在某些低级别构建基块上，此代码实际上是相对较窄的外观，用于更常见的侦听。

侦听接口Interception interfaces

拦截代码是围绕截取接口的概念构建的。 这些接口从 IDbInterceptor 继承，并定义在 EF 执行某个操作时调用的方法。 目的是要截获每种类型的对象的一个接口。 例如，IDbCommandInterceptor 接口定义在 EF 调用 ExecuteNonQuery、ExecuteScalar、ExecuteReader 和相关方法之前调用的方法。 同样，接口会定义在这些操作完成时调用的方法。 以上所示的 DatabaseLogFormatter 类实现此接口来记录命令。

截获上下文The interception context

查看在任何侦听器接口上定义的方法很明显，就是每个调用都给定 DbInterceptionContext 类型的对象或派生的某种类型，如 DbCommandInterceptionContext<>。 此对象包含有关 EF 正在采取的操作的上下文信息。 例如，如果该操作是代表 DbContext 执行的，则 DbContext 将包含在 DbInterceptionContext 中。 同样，对于异步执行的命令，将在 DbCommandInterceptionContext 上设置 IsAsync 标志。

结果处理Result handling

DbCommandInterceptionContext<> 类包含一个名为 Result、OriginalResult、Exception 和 OriginalException 的属性。 对于对在执行操作之前调用的截取方法的调用，这些属性将设置为 null/零（即，对于 。正在执行方法。 如果执行并成功执行该操作，则结果和 OriginalResult 将设置为操作的结果。 然后，可以在执行操作后调用的截取方法中观察这些值，即 。已执行方法。 同样，如果操作引发，则会设置 Exception 和 OriginalException 属性。

禁止执行Suppressing execution

如果侦听器在执行命令之前设置 Result 属性（在其中一个 。执行方法）后，EF 不会尝试实际执行该命令，而只是使用结果集。 换句话说，侦听器可以取消命令的执行，但会继续执行 EF，就像执行命令一样。

通常使用包装提供程序执行的命令批处理就是使用此方法的示例。 侦听器将以批处理的形式存储命令以供以后执行，但会 “假设” 命令已正常执行。 请注意，它需要超过此数目才能实现批处理，但这是如何使用更改截取结果的示例。

还可以通过在其中一个 “…”正在执行方法。 这会导致 EF 通过引发给定异常来继续执行操作。 当然，这可能会导致应用程序崩溃，但也可能是由 EF 处理的暂时性异常或其他异常。 例如，在命令执行失败时，可以在测试环境中使用它来测试应用程序的行为。

在执行后更改结果Changing the result after execution

如果侦听器在执行命令后设置 Result 属性（在其中一个 。执行方法）后，EF 将使用更改后的结果，而不是实际从操作返回的结果。 同样，如果侦听器在执行命令后设置了 Exception 属性，则 EF 将引发设置异常，就好像操作引发了异常一样。

侦听器还可以将 Exception 属性设置为 null，以指示不应引发异常。 如果执行操作失败，则此方法会很有用，但侦听器希望 EF 继续操作，就像操作已成功一样。 这通常还涉及到设置结果，以便 EF 有一些结果值在继续时使用。

OriginalResult 和 OriginalExceptionOriginalResult and OriginalException

在 EF 执行了某一操作后，如果执行未通过，则将设置 Result 和 OriginalResult 属性，如果执行失败但出现异常，则将设置为 Exception 和 OriginalException 属性。

OriginalResult 和 OriginalException 属性是只读的，并且仅在实际执行操作后由 EF 设置。 侦听器不能设置这些属性。 这意味着，任何侦听器都可以区分已由其他侦听器设置的异常或结果，而不是执行操作时所发生的实际异常或结果。

正在注册侦听器Registering interceptors

一旦创建了一个或多个截获接口的类，就可以使用 DbInterception 类向 EF 注册它。 例如：

  1. DbInterception.Add(new NLogCommandInterceptor());

还可以使用基于 DbConfiguration 代码的配置机制在应用域级别注册拦截程序。

示例：记录到 NLogExample: Logging to NLog

让我们将这一切结合起来，使用 IDbCommandInterceptor 和NLog来执行以下操作：

  • 为非异步执行的任何命令记录警告
  • 为执行时引发的任何命令记录错误

下面是执行日志记录的类，应如下所示进行注册：

  1. public class NLogCommandInterceptor : IDbCommandInterceptor
  2. {
  3.     private static readonly Logger Logger = LogManager.GetCurrentClassLogger();
  5.     public void NonQueryExecuting(
  6.         DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
  7.     {
  8.         LogIfNonAsync(command, interceptionContext);
  9.     }
  11.     public void NonQueryExecuted(
  12.         DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
  13.     {
  14.         LogIfError(command, interceptionContext);
  15.     }
  17.     public void ReaderExecuting(
  18.         DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
  19.     {
  20.         LogIfNonAsync(command, interceptionContext);
  21.     }
  23.     public void ReaderExecuted(
  24.         DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
  25.     {
  26.         LogIfError(command, interceptionContext);
  27.     }
  29.     public void ScalarExecuting(
  30.         DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
  31.     {
  32.         LogIfNonAsync(command, interceptionContext);
  33.     }
  35.     public void ScalarExecuted(
  36.         DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
  37.     {
  38.         LogIfError(command, interceptionContext);
  39.     }
  41.     private void LogIfNonAsync<TResult>(
  42.         DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
  43.     {
  44.         if (!interceptionContext.IsAsync)
  45.         {
  46.             Logger.Warn("Non-async command used: {0}", command.CommandText);
  47.         }
  48.     }
  50.     private void LogIfError<TResult>(
  51.         DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
  52.     {
  53.         if (interceptionContext.Exception != null)
  54.         {
  55.             Logger.Error("Command {0} failed with exception {1}",
  56.                 command.CommandText, interceptionContext.Exception);
  57.         }
  58.     }
  59. }

请注意，此代码如何使用侦听上下文来发现何时以非异步方式执行命令，并在执行命令时发现错误。