Entity Framework Core – logování selectů a doby vykonávání

Časem narazíte na problémy pomalých odezev vašich aplikací. Budete chtít mít představu kdy a jak dlouho co trvalo – kdo neměří ten neřídí. Proto si dnes ukážeme jak logovat vygenerované SQL dotazy včetně jejich časi provedení. Entity Framework defaultně loguje příkazy, které vykonává, ovšem to dost často nestačí. Dnes si ukážeme jak logování rozšířit.

Zabudovaného logování v EF Core

Jedná se o základní jedochudou metodu. V Program.cs máte kód který přidává EF do DI:

//EF
builder.Services.AddDbContext<HulvatContext>(options =>
{
    options.UseSqlServer(builder.Configuration.GetConnectionString("DefaultConnection");
});

Tento kód stačí rozšířit o požadované logování:

//EF
builder.Services.AddDbContext<HulvatContext>(options =>
{
    options.UseSqlServer(builder.Configuration.GetConnectionString("DefaultConnection"))
    .UseLoggerFactory(LoggerFactory.Create(builder => builder.AddConsole()))
    .EnableSensitiveDataLogging();
});

Tím získáme SQL dotaz včetně doby vykonávání:

info: Microsoft.EntityFrameworkCore.Database.Command[20101]
Executed DbCommand (10ms) [Parameters=[@__email_0='test@test.cz' (Size = 50)], CommandType='Text', CommandTimeout='30']
SELECT TOP(1) [u].[Id], [u].[DisplayName], [u].[Email], [u].[FisrtName], [u].[LastName] FROM [Users] AS [u]
WHERE [u].[Email] = @__email_0

Tímto způsobem budou SQL dotazy logovány do konzole. Můžete změnit cíl logování tím, že nahradíte AddConsole() za jiný logger.

EnableSensitiveDataLogging

Při logování SQL dotazů s citlivými daty (sensitive data), můžete použít metodu .EnableSensitiveDataLogging(). Tato metoda zajistí, že citlivá data, jako jsou hesla, nebudou logována.

.NET core – jak logovat s NLog

Nes si ukážeme jak zprovoznit logování přes knihovnu NLog. V této knihovně je možné udělat několik targertů a do každého targetu logovat různé informace. Například pouze chyby logovat do speciálního targetu a posílat si je například emailem, …

Instalace NLog

Install-Package NLog
Install-Package NLog.Web.AspNetCore

Konfigurace NLog

Vytvoříme soubor konfigurace pro NLog, který určuje, kam a jak mají být logy zpracovány. Vytvořte soubor s názvem „nlog.config“ ve vašem projektu (na úrovni souboru appsettings.json):

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  autoReload="true"
  internalLogLevel="info"
  internalLogFile="c:\\_temp\\internallog.txt">
  <extensions>
    <add assembly="NLog.Web.AspNetCore" />
  </extensions>
  <targets>
    <target name="logfile" xsi:type="File" fileName="c:\\_temp\\log.txt" layout="${longdate} ${level:uppercase=true} ${message}"/>
     <target xsi:type="ColoredConsole" name="logconsole" />
  </targets>
  <rules>
    <logger name="Microsoft.*" maxLevel="Info" final="true" />
    <logger name="*" minlevel="Info" writeTo="logfile" />
    <logger name="*" minlevel="Info" writeTo="logconsole" />
  </rules>
</nlog>

Tento konfigurační soubor nastaví logování do souboru „log.txt“ od úrovně „Info“ výše a zahrnuje všechny loggery (názvy hvězdičkou). Můžete dále upravit konfiguraci podle vašich potřeb. Osvědčilo se mi posálání chyb emailem.

Registrujeme NLog v aplikaci

Do souboru Program.cs přidáme:

var logger = NLog.LogManager.Setup().LoadConfigurationFromAppSettings().GetCurrentClassLogger();

//Nlog
builder.Logging.ClearProviders();
builder.Host.UseNLog();

Logujeme v aplikaci

Nyní máme 2 možnosti logování

Logování přes GetCurrentClassLogger

Definujeme a rovnou naplníme field logeru:

private static Logger _logger = LogManager.GetCurrentClassLogger();

který pak používáme:

_logger.Trace("Trace");
_logger.Debug("Debug");
_logger.Info("Info");
_logger.Warn("Warn");
_logger.Error("Error");

DI ILogger

Přes DI si injecteme logger:

private readonly ILogger _logger;

public UserService(ILogger<UserService> logger)
{

  _logger = logger;
}

Který pak používáme

_logger.LogTrace("Trace");
_logger.LogDebug("Debug");
_logger.LogInformation("Info");
_logger.LogWarning("Warn");
_logger.LogError("Error");