Логгирование операций

Логгирование позволяет нам получить информацию о выполняемых в Entity Framework операциях. Причем использовать как встроенные возможности, так и создать и встроить свою инфраструктуру логгирования. Рассмотрим оба варианта и начнем со встроенных возможностей.

Метод LogTo

Для логгирования информации можно использовать метод LogTo(). Он применяется при конфигурации класса контекста данных.

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

public class User
{
	public int Id { get; set; }
	public string? Name { get; set; }
	public int Age { get; set; }
}

И следующий класс контекста данных:

using Microsoft.EntityFrameworkCore;

public class ApplicationContext : DbContext
{
    public DbSet<User> Users { get; set; } = null!;
    public ApplicationContext()
    {
        Database.EnsureDeleted();
        Database.EnsureCreated();
    }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlite("Data Source=helloapp.db");
		optionsBuilder.LogTo(Console.WriteLine);
    }
}

В методе OnConfiguring() у передаваемого в качестве параметра объекта DbContextOptionsBuilder вызывается метод LogTo(), в который передается делегат Action<string> - то есть некоторое действие, которое принимает один параметр типа string и и ничего не возвращает. Именно такое действие представляет традиционный метод Console.WriteLine(), который выводит строку на консоль.

Для тестирования пусть у нас определена следующая программа:

using (ApplicationContext db = new ApplicationContext())
{
    User user1 = new User { Name = "Tom", Age = 33 };
    User user2 = new User { Name = "Alice", Age = 26 };

    db.Users.Add(user1);
    db.Users.Add(user2);
    db.SaveChanges();

    var users = db.Users.ToList();
    Console.WriteLine("Список пользователей:");
    foreach (User u in users)
    {
        Console.WriteLine($"{u.Id}.{u.Name} - {u.Age}");
    }
}

И при запуске приложения на консоль будет выведена детальная информация по всем операциям:

Подобным образом можно логгировать в другие места. Например, если мы работаем в Visual Studio, то мы можем логгировать операции в окно Output с помощью метода Debug.WriteLine():

optionsBuilder.LogTo(message => System.Diagnostics.Debug.WriteLine(message));

Другим распространенным способом логгирования является вывод в файл:

using Microsoft.EntityFrameworkCore;

public class ApplicationContext : DbContext
{
    readonly StreamWriter logStream = new StreamWriter("mylog.txt", true);
    public DbSet<User> Users { get; set; } = null!;
    public ApplicationContext()
    {
        Database.EnsureDeleted();
        Database.EnsureCreated();
    }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlite("Data Source=helloapp.db");
        optionsBuilder.LogTo(logStream.WriteLine);
    }
    public override void Dispose()
    {
        base.Dispose();
        logStream.Dispose();
    }

    public override async ValueTask DisposeAsync()
    {
        await base.DisposeAsync();
        await logStream.DisposeAsync();
    }
}

Собственно для записи в файл используется объект класса StreamWriter из пространства имен System.IO. Его метод logStream.WriteLine, который пищет в файл строку, передается в метод LogTo(). Для закрытия и утилизации файлового потока StreamWriter в классе контекста переопределены методы Dispose/DisposeAsync, в которых вызывается метод Dispose/DisposeAsync объекта StreamWriter. В итоге при выполнении программы в папке приложения появится файл лога mylog.txt.

Настройка логгирования

Уровень логгирования

Метод LogTo() имеет ряд перегруженных версий, которые принимают разное количество параметров. Так, мы можем передать в LogTo уровень логгирования в виде одного из значений перечисления LogLevel:

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

• Debug: для вывода информации, которая может быть полезной в процессе разработки и отладки приложения

• Information: уровень сообщений, позволяющий просто отследить поток выполнения приложения

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

• Error: для вывода информации об ошибках и исключениях, которые возникли при текущей операции и которые не могут быть обработаны

• Critical: уровень критических ошибок, которые требуют немедленной реакции - ошибками операционной системы, потерей данных в бд, переполнение памяти диска и т.д.

• None: вывод информации в лог не применяется

По умолчанию EntityFramework Core использует значение Debug, но можно указать какое-нибудь другое значение:

optionsBuilder.LogTo(Console.WriteLine, LogLevel.Information);

Конкретизация сообщений

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

• SqlServerEventId: описывает сообщения, специфические для провайдера для MS SQL Server

• CoreEventId: описывает сообщения, общие для всех провайдеров Entity Framework Core

• RelationalEventId: описывает сообщения, общие для всех провайдеров для реляционных баз данных

Поскольку каждый класс идентификатора имеет довольно много полей, которые представляют опеделенное сообщение, я не буду подробно расписывать все эти поля. Посмотрим на простом примере, как мы можем конкретизировать сообщения - например, нам надо вывести только выполняемые команды SQL. В этом случае мы можем воспользоваться RelationalEventId и его переменной CommandExecuted, которая представляет окончание выполнения команды:

using Microsoft.EntityFrameworkCore;
using Microsoft.EntityFrameworkCore.Diagnostics;

public class ApplicationContext : DbContext
{
    public DbSet<User> Users { get; set; } = null!;
    public ApplicationContext()
    {
        Database.EnsureDeleted();
        Database.EnsureCreated();
    }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlite("Data Source=helloapp.db");
        optionsBuilder.LogTo(Console.WriteLine, new[] { RelationalEventId.CommandExecuted });
    }
}

Категории сообщений

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

• Database.Command: категория для выполняемых команд, позволяет получить выполняемый код SQL

• Database.Connection : категория для операций подключения к БД

• Database.Transaction : категория для транзакций с бд

• Migration: категория для миграций

• Model: категория для действий, совершаемых при привязке модели

• Query: категория для запросов за исключением тех, что генерируют исполняемый код SQL

• Scaffolding: категория для действий, выполняемых в поцессе обратного инжиниринга (то есть когда по базе данных генерируются классы и класс контекста)

• Update: категория для сообщений вызова DbContext.SaveChanges()

• Infrastructure: категория для всех остальных сообщений

Например, выведем в лог информацию только об исполняемых командах:

optionsBuilder.LogTo(Console.WriteLine, new[] { DbLoggerCategory.Database.Command.Name });