Ведение журнала и перехват операций базы данных

Примечание

Только в EF6 и более поздних версиях. Функции, API и другие возможности, описанные на этой странице, появились в Entity Framework 6. При использовании более ранней версии могут быть неприменимы некоторые или все сведения.

Начиная с Entity Framework 6, в любое время Entity Framework отправляет команду в базу данных. Эта команда может быть перехвачена кодом приложения. чаще всего это используется для ведения журнала SQL, но также может использоваться для изменения или отмены команды.

В частности, EF включает:

  • Свойство Log для контекста, похожее на значение DataContext. log в LINQ to SQL
  • Механизм настройки содержимого и форматирования выходных данных, отправляемых в журнал
  • Низкоуровневые стандартные блоки для перехвата, обеспечивающие более высокий уровень контроля и гибкости

Свойство "журнал контекста"

Свойству DbContext. Database. log может быть присвоено значение Delegate для любого метода, принимающего строку. Чаще всего он используется с любым TextWriter, задавая его методу Write этого TextWriter. все SQL, созданные текущим контекстом, будут зарегистрированы в этом модуле записи. например, следующий код будет записывать SQL в консоль:

using (var context = new BlogContext())
{
    context.Database.Log = Console.Write;

    // Your code here...
}

Обратите внимание на этот контекст. База данных. log имеет значение Console. Write. это все, что необходимо для регистрации SQL в консоли.

Давайте добавим простой код запроса, вставки или обновления, чтобы мы могли увидеть выходные данные:

using (var context = new BlogContext())
{
    context.Database.Log = Console.Write;

    var blog = context.Blogs.First(b => b.Title == "One Unicorn");

    blog.Posts.First().Title = "Green Eggs and Ham";

    blog.Posts.Add(new Post { Title = "I do not like them!" });

    context.SaveChangesAsync().Wait();
}

При этом будут созданы следующие выходные данные:

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)
-- Executing at 10/8/2013 10:55:41 AM -07:00
-- Completed in 4 ms with result: SqlDataReader

SELECT
    [Extent1].[Id] AS [Id],
    [Extent1].[Title] AS [Title],
    [Extent1].[BlogId] AS [BlogId]
    FROM [dbo].[Posts] AS [Extent1]
    WHERE [Extent1].[BlogId] = @EntityKeyValue1
-- EntityKeyValue1: '1' (Type = Int32)
-- Executing at 10/8/2013 10:55:41 AM -07:00
-- Completed in 2 ms with result: SqlDataReader

UPDATE [dbo].[Posts]
SET [Title] = @0
WHERE ([Id] = @1)
-- @0: 'Green Eggs and Ham' (Type = String, Size = -1)
-- @1: '1' (Type = Int32)
-- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
-- Completed in 12 ms with result: 1

INSERT [dbo].[Posts]([Title], [BlogId])
VALUES (@0, @1)
SELECT [Id]
FROM [dbo].[Posts]
WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()
-- @0: 'I do not like them!' (Type = String, Size = -1)
-- @1: '1' (Type = Int32)
-- Executing asynchronously at 10/8/2013 10:55:41 AM -07:00
-- Completed in 2 ms with result: SqlDataReader

(Обратите внимание, что это выходная причина, при которой Инициализация базы данных уже выполнена. Если инициализация базы данных еще не была выполнена, будет выведено гораздо больше выходных данных, показывающих, что все операции миграции проводятся на условиях проверки или создания новой базы данных.)

Что регистрируется?

Если для свойства Log задано значение, будут занесены в журнал следующие данные:

  • SQL для всех различных типов команд. Пример:
    • Запросы, включая обычные запросы LINQ, запросы eSQL и необработанные запросы из таких методов, как SqlQuery
    • Операции вставки, обновления и удаления, созданные как часть SaveChanges
    • Запросы на загрузку связей, например, созданные отложенной загрузкой
  • Параметры
  • Выполняется ли команда асинхронно
  • Отметка времени, указывающая время начала исполнения команды
  • Завершилась ли команда успешно, с ошибкой, вызывая исключение или, для асинхронной операции было отменено
  • Указание результирующего значения
  • Приблизительное количество времени, затраченного на выполнение команды. Обратите внимание, что это время от отправки команды для возвращения объекта результата. Он не включает время на чтение результатов.

Просмотрев приведенный выше пример выходных данных, каждая из четырех команд записала в журнал:

  • Запрос, полученный в результате вызова контекста. Блоги. First
    • обратите внимание, что метод tostring для получения SQL не работал для этого запроса, так как "First" не предоставляет iqueryable для вызова ToString.
  • Запрос, полученный в результате отложенной загрузки блога. Публиковать
    • Обратите внимание на сведения о параметре для значения ключа, для которого происходит отложенная загрузка.
    • Регистрируются только свойства параметра, для которых заданы значения, отличные от значений по умолчанию. Например, свойство Size отображается только в том случае, если оно не равно нулю.
  • Две команды, являющиеся результатом SaveChangesAsync; один для обновления, чтобы изменить заголовок записи, другой для вставки, чтобы добавить новую запись.
    • Обратите внимание на подробные сведения о параметрах для свойств FK и Title.
    • Обратите внимание, что эти команды выполняются асинхронно.

Ведение журнала в различных местах

Как показано выше, ведение журнала в консоли очень просто. Кроме того, можно легко выполнять вход в память, файл и т. д., используя различные виды TextWriter.

если вы знакомы с LINQ to SQL можно заметить, что в LINQ to SQL свойству log присвоено значение фактического объекта TextWriter (например, Console. Out), в то время как в EF свойству log присваивается метод, принимающий строку (например, console. Write или console. Out. write). Причина заключается в разделении EF из TextWriter путем приема любого делегата, который может действовать в качестве приемника для строк. Например, представьте, что у вас уже есть какая-либо платформа ведения журналов, и он определяет метод ведения журнала следующим образом:

public class MyLogger
{
    public void Log(string component, string message)
    {
        Console.WriteLine("Component: {0} Message: {1} ", component, message);
    }
}

Это можно подключить к свойству log в журнале EF следующим образом:

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

Журнал результатов

средство ведения журнала по умолчанию регистрирует текст команды (SQL), параметры и строку "выполнение" с меткой времени перед отправкой команды в базу данных. Строка "Completed", содержащая затраченное время, регистрируется после выполнения команды.

Обратите внимание, что для асинхронных команд строка "Completed" не регистрируется, пока асинхронная задача не завершается, не завершается или отменяется.

Строка "завершено" содержит различные сведения в зависимости от типа команды, а также от того, завершилось ли выполнение успешно.

Успешное выполнение

Для команд, которые успешно выполняются, выводится значение "завершено в x мс с результатом:", за которым следует указание на результат. Для команд, возвращающих модуль чтения данных, указание результата является типом возвращаемого DbDataReader . Для команд, возвращающих целочисленное значение, например, команда обновления, показанная выше, выводит это целое число.

Сбой выполнения

Для команд, которые завершились ошибкой, вызывая исключение, выходные данные содержат сообщение из исключения. Например, использование SqlQuery для запроса к существующей таблице приведет к выходу журнала примерно следующего вида:

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

Выполнение отменено

для асинхронных команд, в которых задача отменена, результат может быть неудачным с исключением, так как именно базовый поставщик ADO.NET часто выполняет попытку отмены. Если это не происходит и задача отменяется без каких-либо действий, выходные данные будут выглядеть примерно так:

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

Изменение содержимого и форматирования журнала

В разделе описывается свойство Database. log, использующее объект Датабаселогформаттер. Этот объект эффективно привязывает реализацию Идбкоммандинтерцептор (см. ниже) к делегату, который принимает строки и DbContext. Это означает, что методы в Датабаселогформаттер вызываются до и после выполнения команд с помощью EF. Эти методы Датабаселогформаттер собирают и отформатируют выходные данные журнала и отправляют их делегату.

Настройка Датабаселогформаттер

Изменение журнала и его форматирование можно достичь, создав новый класс, производный от Датабаселогформаттер, и переопределяет методы соответствующим образом. Ниже перечислены наиболее распространенные методы переопределения.

  • Логкомманд — Переопределите этот метод, чтобы изменить способ записи команд перед их выполнением. По умолчанию Логкомманд вызывает Логпараметер для каждого параметра; Вместо этого вы можете сделать то же самое в переопределении или обработке параметров.
  • Логресулт — Переопределите этот параметр, чтобы изменить способ выполнения команды в журнале.
  • Логпараметер — Переопределите этот параметр, чтобы изменить форматирование и содержимое журнала параметров.

Например, предположим, что мы хотим записать только одну строку перед отправкой каждой команды в базу данных. Это можно сделать с помощью двух переопределений:

  • Переопределите Логкомманд, чтобы отформатировать и записать одну строку SQL
  • Переопределите Логресулт, чтобы ничего не делать.

Код должен выглядеть следующим образом:

public class OneLineFormatter : DatabaseLogFormatter
{
    public OneLineFormatter(DbContext context, Action<string> writeAction)
        : base(context, writeAction)
    {
    }

    public override void LogCommand<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        Write(string.Format(
            "Context '{0}' is executing command '{1}'{2}",
            Context.GetType().Name,
            command.CommandText.Replace(Environment.NewLine, ""),
            Environment.NewLine));
    }

    public override void LogResult<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
    }
}

Чтобы журнал выводился, просто вызовите метод Write, который будет передавать выходные данные в настроенный делегат записи.

(Обратите внимание, что этот код позволяет упрощенно удалить разрывы строк, как в примере. Скорее всего, это не будет хорошо работать для просмотра сложных SQL.)

Настройка Датабаселогформаттер

После создания нового класса Датабаселогформаттер его необходимо зарегистрировать с помощью EF. Это выполняется с помощью конфигурации на основе кода. В двух словах это означает создание нового класса, производного от DbConfiguration в той же сборке, что и класс DbContext, а затем вызов Сетдатабаселогформаттер в конструкторе этого нового класса. Пример:

public class MyDbConfiguration : DbConfiguration
{
    public MyDbConfiguration()
    {
        SetDatabaseLogFormatter(
            (context, writeAction) => new OneLineFormatter(context, writeAction));
    }
}

Использование New Датабаселогформаттер

Этот новый Датабаселогформаттер теперь будет использоваться в любое время в любом месте базы данных. log. Таким образом, выполнение кода из части 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)'
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'
Context 'BlogContext' is executing command 'update [dbo].[Posts]set [Title] = @0where ([Id] = @1)'
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()'

Стандартные блоки перехвата

до сих пор мы рассмотрели, как использовать DbContext. Database. log для записи в журнал SQL, созданного EF. Но этот код на самом деле является относительно тонкой фасаднойой на некоторых низкоуровневых стандартных блоках для более общего перехвата.

Интерфейсы перехвата

Код перехвата построен вокруг концепции интерфейсов перехвата. Эти интерфейсы наследуют от Идбинтерцептор и определяют методы, которые вызываются, когда EF выполняет какое – то действие. Цель заключается в том, чтобы в каждом типе объекта перехватываться один интерфейс. Например, интерфейс Идбкоммандинтерцептор определяет методы, вызываемые перед тем, как EF выполняет вызов ExecuteNonQuery, ExecuteScalar, ExecuteReader и связанных методов. Аналогичным образом, интерфейс определяет методы, вызываемые при завершении каждой из этих операций. Класс Датабаселогформаттер, который мы рассматривали выше, реализует этот интерфейс для команд журнала.

Контекст перехвата

Просмотр методов, определенных в любом из интерфейсов перехватчика, очевидно, что каждому вызову присваивается объект типа Дбинтерцептионконтекст или некоторый тип, производный от такого типа, как Дбкоммандинтерцептионконтекст <> . Этот объект содержит контекстные сведения о действии, которое принимает EF. Например, если действие выполняется от имени DbContext, то DbContext включается в Дбинтерцептионконтекст. Аналогично, для команд, выполняемых асинхронно, флагом "Async" задано значение для Дбкоммандинтерцептионконтекст.

Обработка результатов

Класс Дбкоммандинтерцептионконтекст <> содержит свойства results, оригиналресулт, Exception и оригиналексцептион. Для вызовов методов перехвата, которые вызываются перед выполнением операции (то есть для...), для этих свойств устанавливается значение null или нуль. Выполняются методы. Если операция выполняется и проходит успешный результат, то Result и Оригиналресулт устанавливаются в результате операции. Затем эти значения можно наблюдать в методах перехвата, которые вызываются после выполнения операции, то есть в... Выполненные методы. Аналогично, если операция создает исключение, будут заданы свойства Exception и Оригиналексцептион.

Подавление выполнения

Если перехватчик задает свойство Result перед выполнением команды (в одном из... Выполнение методов), то EF не будет пытаться фактически выполнить команду, но вместо этого будет использовать результирующий набор. Иными словами, перехватчик может подавить выполнение команды, но элемент EF продолжит работу, как если бы команда была выполнена.

Пример того, как это можно использовать, — пакетная обработка команд, которая традиционно была выполнена с помощью поставщика обертки. Перехватчик сохранит команду для последующего выполнения в виде пакета, но получит EF, что команда была выполнена как нормальная. Обратите внимание, что для реализации пакетной обработки требуется больше, чем это необходимо, но это пример того, как может использоваться изменение результата перехвата.

Выполнение можно также отключить, задав свойство исключения в одном из... Выполняются методы. Это приводит к тому, что EF будет продолжать работу, как если бы выполнение операции завершилось сбоем, вызывая данное исключение. Это, конечно, может привести к сбою приложения, но оно также может быть временным исключением или другим исключением, которое обрабатывается EF. Например, это можно использовать в тестовых средах для проверки поведения приложения при сбое выполнения команды.

Изменение результата после выполнения

Если перехватчик задает свойство Result после выполнения команды (в одном из... Выполненные методы), то EF будет использовать измененный результат вместо результата, который фактически был возвращен из операции. Аналогично, если перехватчик задает свойство Exception после выполнения команды, то EF вызовет исключение Set, как если бы операция вызывала исключение.

Перехватчик также может установить свойство Exception в значение null, чтобы указать, что исключение не должно выдаваться. Это может быть полезно, если выполнение операции завершилось сбоем, но перехватчик желает продолжить, как если бы операция была выполнена успешно. Как правило, это подразумевает задание результата, чтобы EF получил некоторое значение результата, когда оно продолжит работу.

Оригиналресулт и Оригиналексцептион

После того как EF выполнил операцию, она задаст свойства Result и Оригиналресулт, если выполнение не завершилось сбоем, или свойства Exception и Оригиналексцептион в случае сбоя выполнения с исключением.

Свойства Оригиналресулт и Оригиналексцептион доступны только для чтения и задаются EF только после фактического выполнения операции. Эти свойства не могут быть заданы перехватчиками. Это означает, что любой перехватчик может отличить исключение или результат, заданные другим перехватчиком, в отличие от реального исключения или результата, возникшего при выполнении операции.

Регистрация перехватчиков

После создания класса, реализующего один или несколько интерфейсов перехвата, его можно зарегистрировать в EF с помощью класса Дбинтерцептион. Пример:

DbInterception.Add(new NLogCommandInterceptor());

Перехватчики также могут быть зарегистрированы на уровне домена приложения с помощью механизма конфигурации на основе кода DbConfiguration.

Пример: ведение журнала в NLog

Давайте перейдем все вместе в пример, в котором используются Идбкоммандинтерцептор и NLog :

  • Заносить в журнал предупреждение для любой команды, которая выполняется не асинхронно
  • Регистрировать ошибку для любой команды, которая вызывается при выполнении

Ниже приведен класс, который выполняет ведение журнала, которое должно быть зарегистрировано, как показано выше:

public class NLogCommandInterceptor : IDbCommandInterceptor
{
    private static readonly Logger Logger = LogManager.GetCurrentClassLogger();

    public void NonQueryExecuting(
        DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void NonQueryExecuted(
        DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    public void ReaderExecuting(
        DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void ReaderExecuted(
        DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    public void ScalarExecuting(
        DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        LogIfNonAsync(command, interceptionContext);
    }

    public void ScalarExecuted(
        DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
    {
        LogIfError(command, interceptionContext);
    }

    private void LogIfNonAsync<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        if (!interceptionContext.IsAsync)
        {
            Logger.Warn("Non-async command used: {0}", command.CommandText);
        }
    }

    private void LogIfError<TResult>(
        DbCommand command, DbCommandInterceptionContext<TResult> interceptionContext)
    {
        if (interceptionContext.Exception != null)
        {
            Logger.Error("Command {0} failed with exception {1}",
                command.CommandText, interceptionContext.Exception);
        }
    }
}

Обратите внимание, что этот код использует контекст перехвата, чтобы определить, когда команда выполняется не асинхронно, и определить, когда произошла ошибка при выполнении команды.