Nagy teljesítményű naplózás a .NET-ben

Az LoggerMessage osztály olyan funkciókat tesz elérhetővé, amelyek gyorsítótárazható delegáltakat hoznak létre, amelyek kevesebb objektumfoglalást igényelnek, és kevesebb számítási többletterhelést igényelnek a naplózó bővítménymetódusaihoz képest, például LogInformation és LogDebug. Nagy teljesítményű naplózási forgatókönyvekhez használja a LoggerMessage mintát.

LoggerMessage a következő teljesítménybeli előnyöket nyújtja a naplózóbővítmények metódusaihoz képest:

• A naplózási bővítmény metódusaihoz "boxing" (konvertálás) típusú értéktípusokra van szükség, például int: object. A LoggerMessage minta elkerüli a ökölvívást azáltal, hogy statikus Action mezőket és bővítménymetszeteket használ erősen gépelt paraméterekkel.
• A naplózó bővítmény metódusainak minden alkalommal elemezniük kell az üzenetsablont (elnevezett formátumsztringet), amikor naplóüzenetet írnak. LoggerMessage csak egyszer kell elemezni egy sablont az üzenet definiálásakor.

A mintaalkalmazás egy prioritási LoggerMessage üzenetsor-feldolgozó feldolgozó szolgáltatás funkcióit mutatja be. Az alkalmazás prioritási sorrendben dolgozza fel a munkaelemeket. A műveletek során a rendszer naplóüzeneteket hoz létre a mintával LoggerMessage .

Naplózó üzenetének definiálása

A Define (LogLevel, EventId, String) használatával hozzon létre egy Action delegáltat az üzenetek naplózásához. Define a túlterhelések legfeljebb hat típusparamétert adhatnak át egy nevesített formátumsztringnek (sablonnak).

A metódushoz Define megadott sztring egy sablon, és nem interpolált sztring. A helyőrzőket a típusok megadásának sorrendjében tölti ki a rendszer. A sablon helyőrzőinek leírónak és konzisztensnek kell lenniük a sablonok között. Tulajdonságnévként szolgálnak a strukturált naplóadatokban. A helyőrzők neveihez a Pascal-burkolatot javasoljuk. Például: {Item}. {DateTime}

Minden naplóüzenet egy Action statikus mezőben található, amelyet a LoggerMessage.Define hozott létre. A mintaalkalmazás például létrehoz egy mezőt, amely leírja a munkaelemek feldolgozására vonatkozó naplóüzenetet:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

Adja meg a Actionkövetkezőt:

• A naplószint.
• Egyedi eseményazonosító (EventId) a statikus bővítménymetódus nevével.
• Az üzenetsablon (elnevezett formátumsztring).

A munkaelemek feldolgozásra való lekérdezése során a feldolgozói szolgáltatásalkalmazás a következőt állítja be:

• Naplószint – LogLevel.Critical.
• Eseményazonosító a 13 metódus nevével FailedToProcessWorkItem .
• Üzenetsablon (elnevezett formátumsztring) egy sztringre.

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

A LoggerMessage.Define metódus egy delegált konfigurálására és definiálására Action szolgál, amely egy naplóüzenetet jelöl.

A strukturált naplózási tárolók akkor használhatják az eseménynevet, ha az eseményazonosítóval együtt adják meg a naplózás bővítéséhez. A Serilog például az esemény nevét használja.

A Action meghívás egy erősen beírt bővítménymetóduson keresztül történik. A PriorityItemProcessed metódus minden munkaelem feldolgozásakor naplózza az üzenetet. FailedToProcessWorkItem a rendszer meghívja, ha és amikor kivétel történik:

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

Vizsgálja meg az alkalmazás konzolkimenetét:

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

Ha paramétereket szeretne átadni egy naplóüzenetnek, legfeljebb hat típust definiálhat a statikus mező létrehozásakor. A mintaalkalmazás naplózza a munkaelem részleteit az elemek feldolgozásakor a mező típusának WorkItemAction meghatározásával:

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

A meghatalmazott naplóüzenetsablonja a megadott típusoktól kapja meg a helyőrző értékeit. A mintaalkalmazás egy delegáltat határoz meg egy olyan munkaelem hozzáadásához, amelyben az elemparaméter a WorkItemkövetkező:

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

A munkaelem feldolgozásának naplózására szolgáló statikus bővítménymetódus megkapja a munkaelem argumentumértékét, PriorityItemProcessedés átadja a Action meghatalmazottnak:

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

A munkavégző szolgáltatás metódusában ExecuteAsyncPriorityItemProcessed az üzenet naplózására van meghívva:

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

Vizsgálja meg az alkalmazás konzolkimenetét:

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

Naplózó üzenet hatókörének definiálása

A DefineScope(sztring) metódus létrehoz egy delegáltat Func<TResult> a napló hatókörének meghatározásához. DefineScope a túlterhelések legfeljebb hat típusparamétert adhatnak át egy nevesített formátumsztringnek (sablonnak).

Ahogyan a Define metódus esetében is, a metódushoz DefineScope megadott sztring nem interpolált sztring, hanem sablon. A helyőrzőket a típusok megadásának sorrendjében tölti ki a rendszer. A sablon helyőrzőinek leírónak és konzisztensnek kell lenniük a sablonok között. Tulajdonságnévként szolgálnak a strukturált naplóadatokban. A helyőrzők neveihez a Pascal-burkolatot javasoljuk. Például: {Item}. {DateTime}

Adjon meg egy naplóhatókört, amely a metódus használatával DefineScope naplóüzenetek sorozatára alkalmazható. Engedélyezés IncludeScopes a appsettings.json konzolnaplózó szakaszában:

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

Naplóhatókör létrehozásához adjon hozzá egy mezőt, amely egy delegáltat tart Func<TResult> a hatókörhöz. A mintaalkalmazás létrehoz egy (Belső/LoggerExtensions.cs) nevű s_processingWorkScope mezőt:

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

A meghatalmazott létrehozásához használható DefineScope . A meghatalmazott meghívása esetén legfeljebb hat típus adható meg sablonargumentumként való használatra. A mintaalkalmazás egy üzenetsablont használ, amely tartalmazza a feldolgozás megkezdésének dátumát:

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

Adjon meg egy statikus bővítménymetódust a naplóüzenethez. Adjon meg bármilyen típusparamétert az üzenetsablonban megjelenő elnevezett tulajdonságokhoz. A mintaalkalmazás bevesz egy DateTime egyéni időbélyeget a naplóba, és visszaadja a következőt _processingWorkScope:

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

A hatókör egy használatblokkba csomagolja a naplózási bővítmény hívásait:

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

Vizsgálja meg a naplóüzeneteket az alkalmazás konzoljának kimenetében. Az alábbi eredmény a naplóüzenetek prioritási sorrendbe helyezését mutatja be a napló hatókörére vonatkozó üzenettel együtt:

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...

Naplószintű védett optimalizálások

Egy másik teljesítményoptimalizálás a megfelelő Log* metódus meghívása előtt végzett ellenőrzéssel LogLevelILogger.IsEnabled(LogLevel) végezhető el. Ha a naplózás nincs konfigurálva a megadotthoz LogLevel, a következő utasítások igazak:

• ILogger.Log nincs meghívva.
• A paraméterek hozzárendelése object[] elkerülhető.
• Az értéktípus-bevitel kerülendő.

További információk:

• Mikro teljesítménymutatók a .NET-futtatókörnyezetben
• A naplószintű ellenőrzések háttere és motivációja

Lásd még

• Naplózás a .NET-ben