Logowanie informacji w naszych aplikacjach może być kluczowe przy rozwiązywaniu różnych problemów. Niejednokrotnie wszystko działa w naszym środowisku deweloperskim...kiedy jednak oddajemy aplikacje w ręce testerów okazuje się, że nie wszystko spełnia swoje oczekiwania. W takim wypadku dobrze jest podejrzeć log naszej aplikacji, spojrzeć jakie zapytania zostały wykonane i jaką formę przyjęły. Dotychczas do prezentacji wyników używałem głównie narzędzia SQL Profiler - nie jest to jednak rozwiązanie optymalne.

W przypadku .NET Core oraz EF Core mamy zapewniony mechanizm automatycznej integracji dzięki czemu rejestrowanie kodu SQL i konfiguracja w zależności od środowiska wyjściowego naszego projektu jest niezwykle ułatwiona. Zanim jednak przejdziemy do instalacji odpowiedniej paczki spójrzmy na poniższy diagram pokazujący połączenie pomiędzy konktekstem naszej aplikacji konsolowej a API logowania:

Przechodzimy do konkretów i instalacji pakietu nuget dla naszego projektu konsolowego: Microsoft.Extenstions.Logging.Console.

Po zainstalowaniu paczki musimy utworzyć statyczną instancję LoggerFactory a następnie dokonać powiązania z DbContext. Jeżeli korzystacie z wcześniejszych wersji EF Core poniższe rozwiązanie nie będzie u Was działać:

public class ApplicationDbContext : DbContext
{
	public static readonly ILoggerFactory factory
		= LoggerFactory.Create(builder => { builder.AddConsole(); });

    // Rozwiązanie dla starszych wersji EF Core
    // public static readonly ILoggerFactory loggerFactory = new LoggerFactory(new[] {
    //            new ConsoleLoggerProvider((_, __) => true, true)
    //    });

	public DbSet<Customer> Customer { get; set; }

	public ApplicationDbContext()
	{

	}

	protected override void OnConfiguring(DbContextOptionsBuilder optionBuilder)
	{
		if (!optionBuilder.IsConfigured)
		{
			optionBuilder
				.UseLoggerFactory(factory) // połączenie DBContext z mechanizem logowania
				.UseSqlServer(@"Server=PAWEL;database=EFCoreDisconnected;Integrated Security=true;MultipleActiveResultSets=true").EnableSensitiveDataLogging(true);
		}
	}

Osoby bardziej dociekliwe mogły zobaczyć, że w niektórych wpisach korzystam z EnableSensitiveDataLogging(true) – wszystko dlatego, że od początku przygotowania całego cyklu korzystałem z mechanizmu logowania i rejestrowania poufnych wartości takich jak wartości parametrów poleceń wysyłanych do bazy danych. Chciałem mieć pewność, że przygotowane polecenia są poprawne a śledzenie tych informacji jest domyślnie wyłączone w EF Core.

Przeanalizujmy poniższy kod:

public static readonly ILoggerFactory factory
	= LoggerFactory.Create(builder => { builder.AddConsole();

Nieco niżej w naszej konfiguracji dokonaliśmy powiązania utworzonego obiektu ILoggerFactory z kontekstem wykorzystując DbContextOptionsBuilder:

optionBuilder
	.UseLoggerFactory(factory)

Wykonajmy zatem parametryzowane polecenie w celu prześledzenia wyników operacji w konsoli:

using(var context = new ApplicationDbContext())
{
	string name = "UpdatedPaweł";

	var updatedRows = context.Database
		.ExecuteSqlInterpolated($"UPDATE Customer SET FullName = {name} where Id = 1");
}

warn: Microsoft.EntityFrameworkCore.Model.Validation[10400]
      Sensitive data logging is enabled. Log entries and exception messages may
include sensitive application data; this mode should only be enabled during deve
lopment.
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 5.0.0 initialized 'ApplicationDbContext' using provi
der 'Microsoft.EntityFrameworkCore.SqlServer' with options: SensitiveDataLogging
Enabled
Security Warning: The negotiated TLS 1.0 is an insecure protocol and is supporte
d for backward compatibility only. The recommended protocol version is TLS 1.2 a
nd later.
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (36ms) [Parameters=[@p0='UpdatedPaweł' (Size = 4000)],
CommandType='Text', CommandTimeout='30']
      UPDATE Customer SET FullName = @p0 where Id = 1

Potrzebujemy wszystkich informacji zawartych powyżej? Raczej nie...

Czasami zależmy nam tylko na filtrowaniu określonych kategorii zdarzeń. W Entity Framework Core możemy dokonać konfiguracji określając kategorię i poziom rejestrowanych zdarzeń. W tym celu posłużmy się klasą DbLoggerCategory w której znajdują się poniższe kategorie rejestrowania informacji:

W celu implementacji powyższych założeń musimy nieznacznie zmodyfikować konfigurację LoggerFactory w poniższy sposób określając kategorię i poziom filtrowania informacji:

public static readonly ILoggerFactory factory
	= LoggerFactory.Create(builder => { builder.AddConsole()
		.AddFilter((category, level) =>
		    category == DbLoggerCategory.Database.Command.Name &&
		    level == LogLevel.Information); });

info: Microsoft.EntityFrameworkCore.Database.Command[20101]
    Executed DbCommand (36ms) [Parameters=[@p0='UpdatedPaweł' (Size = 4000)],
    CommandType='Text', CommandTimeout='30']
    UPDATE Customer SET FullName = @p0 where Id = 1