Rejestrowanie o wysokiej wydajności na platformie .NET

W scenariuszach rejestrowania o wysokiej wydajności na platformie .NET 6 i nowszych wersjach użyj LoggerMessageAttribute z generowaniem źródeł podczas kompilacji. Takie podejście zapewnia najlepszą wydajność, eliminując boxing, tymczasowe alokacje i analizowanie szablonów komunikatów w czasie wykonywania.

Rejestrowanie generowane przez źródło zapewnia następujące zalety wydajności w porównaniu z metodami rozszerzenia rejestratora, takimi jak LogInformation i LogDebug:

• Eliminuje opakowanie: Metody rozszerzenia rejestratora wymagają opakowania (konwertowania) typów wartości, takich jak int, na object. Rejestrowanie generowane przez źródło pozwala uniknąć boksowania dzięki użyciu silnie typowanych parametrów.
• Analizuje szablony w czasie kompilacji: Metody rozszerzenia rejestratora muszą analizować szablon komunikatu (nazwany ciąg formatu) za każdym razem, gdy jest zapisywany komunikat dziennika. Wygenerowane przez źródło rejestrowanie analizuje szablony raz w czasie kompilacji.
• Zmniejsza alokacje: Generator źródła tworzy zoptymalizowany kod, który minimalizuje alokacje obiektów i tymczasowe użycie pamięci.

Przykładowa aplikacja demonstruje funkcje rejestrowania o wysokiej wydajności z priorytetową usługą procesu roboczego przetwarzania kolejek. Aplikacja przetwarza elementy robocze w kolejności priorytetu. W miarę występowania tych operacji komunikaty dziennika są generowane przy użyciu logowania generowanego przez źródło.

Wskazówka

Cały przykładowy kod źródłowy rejestrowania jest dostępny w przeglądarce Samples Browser do pobrania. Aby uzyskać więcej informacji, zobacz Przeglądanie przykładów kodu: Rejestrowanie na platformie .NET.

Definiowanie komunikatów rejestratora przy użyciu generowania źródła

Aby utworzyć wysokowydajne komunikaty dziennika na platformie .NET 6 lub nowszej, zdefiniuj partial metody ozdobione LoggerMessageAttribute. Generator źródła tworzy implementację w czasie kompilacji.

Podstawowa metoda rejestrowania

W przypadku prostego komunikatu dziennika zdefiniuj metodę częściową z atrybutem określającym identyfikator zdarzenia, poziom dziennika i szablon komunikatu:

public static partial class Log
{
    [LoggerMessage(
        EventId = 13,
        Level = LogLevel.Critical,
        Message = "Epic failure processing item!")]
    public static partial void FailedToProcessWorkItem(
        ILogger logger, Exception ex);
}

Szablon komunikatu używa symboli zastępczych wypełnionych parametrami metody. Nazwy symboli zastępczych powinny być opisowe i spójne w szablonach. Służą one jako nazwy właściwości w danych dziennika ustrukturyzowanego. Zalecamy używanie pisowni Pascal dla nazw zastępczych. Na przykład , {Item}. {DateTime}

Wywołaj metodę logowania z kodu. Na przykład w przypadku wystąpienia wyjątku podczas przetwarzania elementu roboczego:

try
{
    // Process work item.
}
catch (Exception ex)
{
    Log.FailedToProcessWorkItem(logger, ex);
}

Ten kod generuje dane wyjściowe konsoli, takie jak:

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.

Logowanie za pomocą parametrów

Aby przekazać parametry do komunikatu dziennika, dodaj je jako parametry metody. Nazwy parametrów są zgodne z symbolami zastępczymi w szablonie komunikatu:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Wywołaj metodę przy użyciu wartości rejestratora i parametrów:

var workItem = queue.Dequeue();
Log.PriorityItemProcessed(logger, workItem);

Ten kod generuje dane wyjściowe konsoli, takie jak:

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

Magazyny strukturalnego rejestrowania mogą używać nazwy zdarzenia, gdy jest ona dostarczona wraz z identyfikatorem zdarzenia dla wzbogacenia rejestrowania. Na przykład serilog używa nazwy zdarzenia.

Definiowanie zakresu komunikatów rejestratora przy użyciu generowania źródła

Zakresy dzienników można zdefiniować w celu objęcia serii komunikatów dziennikowych dodatkowym kontekstem. W przypadku rejestrowania generowanego przez źródło można połączyć metody LoggerMessageAttribute ze standardową metodą ILogger.BeginScope.

Włącz IncludeScopes w sekcji loggera konsoli appsettings.json:

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

Utwórz źródłowo-generowane metody logowania i owiń je w zakresie przy użyciu BeginScope:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Użyj metody rejestrowania w obrębie kodu aplikacji.

using (_logger.BeginScope("Processing scope, started at: {DateTime}", DateTime.Now))
{
    Log.PriorityItemProcessed(_logger, workItem);
}

Sprawdź komunikaty dziennika w danych wyjściowych konsoli aplikacji. Poniższy wynik pokazuje priorytetową kolejność komunikatów dziennika zawierających komunikat dotyczący zakresu dziennika.

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'

Starsze podejście: LoggerMessage.Define (dla programów .NET Framework i .NET Core 3.1)

Przed wprowadzeniem rejestrowania generowanego przez źródło w .NET 6 zalecane podejście do rejestrowania o wysokiej wydajności polegało na wykorzystaniu metody LoggerMessage.Define do tworzenia delegatów z możliwością buforowania. Mimo że to podejście jest nadal obsługiwane w celu zapewnienia zgodności z poprzednimi wersjami, nowy kod powinien zamiast tego używać rejestrowania wygenerowanego ze źródła przy użyciu LoggerMessageAttribute.

Klasa LoggerMessage uwidacznia funkcje tworzenia delegatów z możliwością buforowania, które wymagają mniejszej liczby alokacji obiektów i mniejszego obciążenia obliczeniowego w porównaniu z metodami rozszerzenia rejestratora, takimi jak LogInformation i LogDebug. LoggerMessage zapewnia następujące zalety wydajności w porównaniu z metodami rozszerzeń rejestratora:

• Metody rozszerzenia rejestratora wymagają typów wartości typu "boxing" (konwertowanie), takich jak int, na object. Wzorzec LoggerMessage unika tworzenia pól statycznych Action i metod rozszerzeń z silnie typinymi parametrami.
• Metody rozszerzenia rejestratora muszą analizować szablon komunikatu (nazwany ciąg formatu) za każdym razem, gdy jest zapisywany komunikat dziennika. LoggerMessage Wymaga analizowania szablonu tylko raz po zdefiniowaniu komunikatu.

Uwaga / Notatka

Jeśli utrzymujesz kod korzystający z LoggerMessage.Define, rozważ migrację do logowania generowanego przez źródło. W przypadku aplikacji .NET Framework lub .NET Core 3.1 kontynuuj korzystanie z programu LoggerMessage.Define.

Definiowanie komunikatu rejestratora

Użyj funkcji Define(LogLevel, EventId, String), aby utworzyć delegata Action na potrzeby rejestrowania komunikatu. Define przeciążenia umożliwiają przekazywanie maksymalnie sześciu parametrów typu do nazwanego ciągu formatu (szablonu).

Ciąg podany w metodzie Define jest szablonem, a nie ciągiem interpolowanym. Symbole zastępcze są wypełniane w kolejności, w jakiej typy są określone. Nazwy symboli zastępczych w szablonie powinny być opisowe i spójne w szablonach. Służą one jako nazwy właściwości w danych dziennika ustrukturyzowanego. Zalecamy używanie pisowni Pascal dla nazw zastępczych. Na przykład , {Item}. {DateTime}

Każdy komunikat dziennika jest Action przechowywany w polu statycznym utworzonym przez loggerMessage.Define. Na przykład przykładowa aplikacja tworzy pole do opisania komunikatu dziennika na potrzeby przetwarzania elementów roboczych:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

Dla parametru Actionokreśl następujące elementy:

• Poziom logowania.
• Unikatowy identyfikator zdarzenia (EventId) o nazwie metody rozszerzenia statycznego.
• Szablon wiadomości (ciąg formatu o nazwie).

Ponieważ elementy robocze są w kolejce do przetwarzania, aplikacja usługi procesu roboczego ustawia następujące elementy:

• Ustaw poziom dziennika na LogLevel.Critical.
• Identyfikator zdarzenia 13 z nazwą metody FailedToProcessWorkItem.
• Przekształcenie szablonu komunikatu (nazwanego ciągu formatu) w ciąg.

s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

Metoda LoggerMessage.Define służy do konfigurowania i definiowania delegata Action , który reprezentuje komunikat dziennika.

Magazyny strukturalnego rejestrowania mogą używać nazwy zdarzenia, gdy jest ona dostarczona wraz z identyfikatorem zdarzenia dla wzbogacenia rejestrowania. Na przykład serilog używa nazwy zdarzenia.

Element Action jest wywoływany za pomocą silnie typizowanej metody rozszerzenia. Metoda PriorityItemProcessed rejestruje komunikat za każdym razem, gdy element roboczy jest przetwarzany. FailedToProcessWorkItem jest wywoływana, jeśli i kiedy wystąpi wyjątek.

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);
        }
    }
}

Sprawdź dane wyjściowe konsoli aplikacji:

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

Aby przekazać parametry do komunikatu dziennika, zdefiniuj maksymalnie sześć typów podczas tworzenia pola statycznego. Przykładowa aplikacja rejestruje szczegóły elementu roboczego, definiując typ WorkItem dla pola Action podczas przetwarzania elementów.

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

Szablon komunikatu dziennika delegata odbiera wartości symboli zastępczych z podanych typów. Przykładowa aplikacja definiuje delegata do dodawania elementu roboczego, w którym parametr elementu to WorkItem:

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

Statyczna metoda rozszerzająca do rejestrowania, że element roboczy jest przetwarzany, PriorityItemProcessed, otrzymuje wartość argumentu elementu roboczego i przekazuje ją do delegata Action.

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

W metodzie ExecuteAsync usługi roboczej wywoływana jest PriorityItemProcessed w celu zarejestrowania komunikatu:

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);
        }
    }
}

Sprawdź dane wyjściowe konsoli aplikacji:

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

Optymalizacje chronione przez poziom logów

Wydajność można zoptymalizować, sprawdzając element LogLevel za pomocą ILogger.IsEnabled(LogLevel) przed wywołaniem odpowiedniej Log* metody. Jeśli rejestrowanie nie jest skonfigurowane dla danego LogLevel elementu, ILogger.Log nie jest wywołane. Ponadto unika się tworzenia pól typu wartości i alokacji object[] (aby reprezentować parametry).

Aby uzyskać więcej informacji, zobacz:

• Mikro benchmarki w środowisku uruchomieniowym platformy .NET
• Tło i motywacja do sprawdzeń na poziomie logów

Zobacz także

• Rejestrowanie na platformie .NET
• Generowanie źródła rejestrowania w czasie kompilacji