Protokolování s vysokým výkonem v .NET

Třída LoggerMessage zveřejňuje funkce pro vytváření delegátů s možností ukládání do mezipaměti, které vyžadují méně přidělení objektů a nižší výpočetní režii v porovnání s metodami rozšíření protokolovacího nástroje, jako LogInformation jsou a LogDebug. Pro scénáře protokolování s vysokým výkonem LoggerMessage použijte vzor.

LoggerMessage poskytuje následující výhody výkonu oproti metodám rozšíření protokolovacího nástroje:

  • Metody rozšíření protokolovacího nástroje vyžadují "boxing" (převod) hodnotové typy, například int, do object. Vzor LoggerMessage se vyhne boxování pomocí statických Action polí a rozšiřujících metod se silnými parametry.
  • Metody rozšíření protokolovacího nástroje musí analyzovat šablonu zprávy (pojmenovaný formát řetězec) při každém zápisu zprávy protokolu. LoggerMessage Při definování zprávy vyžaduje pouze jednou parsování šablony.

Důležité

Místo použití LoggerMessage třídy k vytvoření vysoce výkonných protokolů můžete použít LoggerMessage atribut v .NET 6 a novějších verzích. Poskytuje LoggerMessageAttribute podporu protokolování generování zdrojů navržená tak, aby poskytovala vysoce použitelné a vysoce výkonné řešení protokolování pro moderní aplikace .NET. Další informace naleznete v tématu Generování zdroje protokolování v čase kompilace (.NET Fundamentals).

Ukázková aplikace ukazuje LoggerMessage funkce s pracovní službou zpracování fronty s prioritou. Aplikace zpracovává pracovní položky v pořadí priority. Jak k těmto operacím dochází, zprávy protokolu se generují pomocí LoggerMessage vzoru.

Tip

Veškerý zdrojový kód příkladu protokolování je k dispozici v prohlížeči ukázek ke stažení. Další informace najdete v tématu Procházení ukázek kódu: Protokolování v .NET.

Definování zprávy protokolovacího nástroje

K vytvoření delegáta Action pro protokolování zprávy použijte Define(LogLevel, EventId, String). Define přetížení umožňují předat až šest parametrů typu do pojmenovaného řetězce formátu (šablony).

Řetězec poskytnutý metodě Define je šablona, nikoli interpolovaný řetězec. Zástupné symboly se vyplní v pořadí, v jakém jsou zadané typy. Zástupné názvy v šabloně by měly být popisné a konzistentní napříč šablonami. Slouží jako názvy vlastností v rámci strukturovaných dat protokolu. Pro zástupné názvy doporučujeme vkládat písmena Pascalu. Například , {Item}{DateTime}.

Každá zpráva protokolu je uložena Action ve statickém poli vytvořeném loggerMessage.Define. Ukázková aplikace například vytvoří pole pro popis zprávy protokolu pro zpracování pracovních položek:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

V poli Actionzadejte:

  • Úroveň protokolování
  • Jedinečný identifikátor události (EventId) s názvem metody statického rozšíření.
  • Šablona zprávy (pojmenovaný formátovací řetězec)

Vzhledem k tomu, že pracovní položky jsou vyřazeny z fronty pro zpracování, aplikace pracovní služby nastaví:

  • Úroveň protokolu do LogLevel.Critical.
  • ID události s 13 názvem FailedToProcessWorkItem metody.
  • Šablona zprávy (řetězec pojmenovaného formátu) na řetězec
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

Metoda LoggerMessage.Define se používá ke konfiguraci a definování delegáta Action , který představuje zprávu protokolu.

Úložiště strukturovaného protokolování můžou použít název události, pokud je k obohacení protokolování dodáno s ID události. Například Serilog používá název události.

Vyvolá se Action prostřednictvím metody rozšíření silného typu. Metoda PriorityItemProcessed zaznamená zprávu při každém zpracování pracovní položky. FailedToProcessWorkItem je volána, pokud a když dojde k výjimce:

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Zkontrolujte výstup konzoly aplikace:

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.
         at WorkerServiceOptions.Example.Worker.ExecuteAsync(CancellationToken stoppingToken) in
         ..\Worker.cs:line 27

Pokud chcete předat parametry do zprávy protokolu, definujte při vytváření statického pole až šest typů. Ukázková aplikace zaznamená podrobnosti pracovní položky při zpracování položek definováním WorkItem typu pole Action :

private static readonly Action<ILogger, WorkItem, Exception> s_processingPriorityItem;

Šablona zprávy protokolu delegáta obdrží zástupné hodnoty z zadaných typů. Ukázková aplikace definuje delegáta pro přidání pracovní položky, kde je WorkItemparametr položky:

s_processingPriorityItem = LoggerMessage.Define<WorkItem>(
    LogLevel.Information,
    new EventId(1, nameof(PriorityItemProcessed)),
    "Processing priority item: {Item}");

Statická metoda rozšíření pro protokolování, že pracovní položka je zpracovávána, PriorityItemProcessedobdrží hodnotu argumentu pracovní položky a předá ji delegátu Action :

public static void PriorityItemProcessed(
    this ILogger logger, WorkItem workItem) =>
    s_processingPriorityItem(logger, workItem, default!);

V metodě PriorityItemProcessed pracovní služby ExecuteAsync je volána k protokolování zprávy:

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Zkontrolujte výstup konzoly aplikace:

info: WorkerServiceOptions.Example.Worker[1]
      Processing priority item: Priority-Extreme (50db062a-9732-4418-936d-110549ad79e4): 'Verify communications'

Definování rozsahu zpráv protokolovacího modulu

Metoda DefineScope(string) vytvoří Func<TResult> delegáta pro definování oboru protokolu. DefineScope přetížení umožňují předat až šest parametrů typu do pojmenovaného řetězce formátu (šablony).

Stejně jako v případě Define metody je řetězec poskytnutý metodě DefineScope šablona, nikoli interpolovaný řetězec. Zástupné symboly se vyplní v pořadí, v jakém jsou zadané typy. Zástupné názvy v šabloně by měly být popisné a konzistentní napříč šablonami. Slouží jako názvy vlastností v rámci strukturovaných dat protokolu. Pro zástupné názvy doporučujeme vkládat písmena Pascalu. Například , {Item}{DateTime}.

Definujte obor protokolu, který se má použít na řadu zpráv protokolu pomocí DefineScope metody. V části nástroje pro protokolování konzoly appsettings.json povolteIncludeScopes:

{
    "Logging": {
        "Console": {
            "IncludeScopes": true
        },
        "LogLevel": {
            "Default": "Information",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information"
        }
    }
}

Pokud chcete vytvořit obor protokolu, přidejte pole pro uložení delegáta Func<TResult> pro daný obor. Ukázková aplikace vytvoří pole s názvem s_processingWorkScope (Internal/LoggerExtensions.cs):

private static readonly Func<ILogger, DateTime, IDisposable?> s_processingWorkScope;

Slouží DefineScope k vytvoření delegáta. Při vyvolání delegáta je možné zadat až šest typů pro použití jako argumenty šablony. Ukázková aplikace používá šablonu zprávy, která obsahuje datum a čas, ve kterém se zpracování spustilo:

s_processingWorkScope =
    LoggerMessage.DefineScope<DateTime>(
        "Processing scope, started at: {DateTime}");

Zadejte statickou metodu rozšíření pro zprávu protokolu. Zahrňte všechny parametry typu pro pojmenované vlastnosti, které se zobrazí v šabloně zprávy. Ukázková aplikace přebírá DateTime vlastní časové razítko pro protokolování a vrací _processingWorkScope:

public static IDisposable? ProcessingWorkScope(
    this ILogger logger, DateTime time) =>
    s_processingWorkScope(logger, time);

Obor zabalí volání rozšíření protokolování do bloku using :

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Zkontrolujte zprávy protokolu ve výstupu konzoly aplikace. Následující výsledek ukazuje řazení zpráv protokolu s zahrnutými zprávami oboru protokolu:

info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Extreme (7d153ef9-8894-4282-836a-8e5e38319fb3): 'Verify communications'
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\source\repos\dotnet-docs\docs\core\extensions\snippets\logging\worker-service-options
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-High (dbad6558-60cd-4eb1-8531-231e90081f62): 'Validate collection'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1eabe213-dc64-4e3a-9920-f67fe1dfb0f6): 'Propagate selections'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1142688d-d4dc-4f78-95c5-04ec01cbfac7): 'Enter pooling [contention]'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Low (e85e0c4d-0840-476e-b8b0-22505c08e913): 'Health check network'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (07571363-d559-4e72-bc33-cd8398348786): 'Ping weather service'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (2bf74f2f-0198-4831-8138-03368e60bd6b): 'Set process state'
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...

Optimalizace na úrovni protokolů

Další optimalizaci výkonu lze provést kontrolou LogLevel, s ILogger.IsEnabled(LogLevel) před vyvoláním odpovídající Log* metody. Pokud pro dané LogLevelnastavení není nakonfigurované protokolování, platí následující příkazy:

  • ILogger.Log není volána.
  • Přidělení reprezentace object[] parametrů se vyhne.
  • Pole typu hodnota se vyhne.

Další informace:

Viz také