Pengelogan berkinerja tinggi di .NET

  • Artikel

Kelas LoggerMessage mengekspos fungsionalitas untuk membuat delegasi yang dapat di-cache yang memerlukan lebih sedikit alokasi objek dan mengurangi overhead komputasi dibandingkan dengan metode ekstensi pencatat, seperti LogInformation dan LogDebug. Untuk skenario pengelogan berkinerja tinggi, gunakan LoggerMessage pola .

LoggerMessage memberikan keunggulan performa berikut daripada metode ekstensi pencatat:

  • Metode ekstensi pencatat memerlukan jenis nilai "tinju" (mengonversi), seperti int, menjadi object. Pola menghindari LoggerMessage tinju dengan menggunakan bidang statis Action dan metode ekstensi dengan parameter yang sangat ditik.
  • Metode ekstensi pencatat harus mengurai templat pesan (string format bernama) setiap kali pesan log ditulis. LoggerMessage hanya memerlukan penguraian templat sekali ketika pesan ditentukan.

Penting

Alih-alih menggunakan kelas LoggerMessage untuk membuat log berkinerja tinggi, Anda dapat menggunakan atribut LoggerMessage di .NET 6 dan versi yang lebih baru. Menyediakan LoggerMessageAttribute dukungan pengelogan generasi sumber yang dirancang untuk memberikan solusi pengelogan yang sangat dapat digunakan dan berkinerja tinggi untuk aplikasi .NET modern. Untuk informasi selengkapnya, lihat Pembuatan sumber pengelogan waktu kompilasi (.NET Fundamentals).

Aplikasi sampel menunjukkan LoggerMessage fitur dengan layanan pekerja pemrosesan antrean prioritas. Aplikasi memproses item kerja dalam urutan prioritas. Saat operasi ini terjadi, pesan log dihasilkan menggunakan LoggerMessage pola .

Tip

Semua contoh pengelogan kode sumber tersedia di Browser Sampel untuk diunduh. Untuk informasi selengkapnya, lihat Menelusuri sampel kode: Pengelogan di .NET.

Menentukan pesan pencatat

Gunakan Define(LogLevel, EventId, String) untuk membuat Action delegasi untuk mencatat pesan. Define kelebihan beban mengizinkan meneruskan hingga enam parameter jenis ke string format bernama (templat).

String yang disediakan untuk Define metode adalah templat dan bukan string terinterpolasi. Tempat penampung diisi dalam urutan jenis yang ditentukan. Nama tempat penampung dalam templat harus deskriptif dan konsisten di seluruh templat. Mereka berfungsi sebagai nama properti dalam data log terstruktur. Kami merekomendasikan casing Pascal untuk nama tempat penampung. Misalnya, {Item}, {DateTime}.

Setiap pesan log disimpan Action di bidang statis yang dibuat oleh LoggerMessage.Define. Misalnya, aplikasi sampel membuat bidang untuk menjelaskan pesan log untuk pemrosesan item kerja:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

ActionUntuk , tentukan:

  • Tingkat log.
  • Pengidentifikasi peristiwa unik (EventId) dengan nama metode ekstensi statis.
  • Templat pesan (string format bernama).

Saat item kerja dihentikan untuk diproses, aplikasi layanan pekerja mengatur:

  • Tingkat log ke LogLevel.Critical.
  • ID Peristiwa ke 13 dengan nama FailedToProcessWorkItem metode .
  • Templat pesan (string format bernama) ke string.
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

Metode LoggerMessage.Define ini digunakan untuk mengonfigurasi dan menentukan Action delegasi, yang mewakili pesan log.

Penyimpanan pengelogan terstruktur dapat menggunakan nama peristiwa saat disediakan dengan ID peristiwa untuk memperkaya pengelogan. Misalnya, Serilog menggunakan nama peristiwa.

Action dipanggil melalui metode ekstensi yang sangat ditik. Metode mencatat PriorityItemProcessed pesan setiap kali item kerja diproses. FailedToProcessWorkItem dipanggil jika dan ketika pengecualian terjadi:

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

Periksa output konsol aplikasi:

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

Untuk meneruskan parameter ke pesan log, tentukan hingga enam jenis saat membuat bidang statis. Aplikasi sampel mencatat detail item kerja saat memproses item dengan menentukan WorkItem jenis untuk Action bidang :

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

Templat pesan log delegasi menerima nilai tempat penampungnya dari jenis yang disediakan. Aplikasi sampel menentukan delegasi untuk menambahkan item kerja di mana parameter item adalah WorkItem:

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

Metode ekstensi statis untuk pengelogan bahwa item kerja sedang diproses, PriorityItemProcessed, menerima nilai argumen item kerja dan meneruskannya ke Action delegasi:

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

Dalam metode layanan ExecuteAsync pekerja, PriorityItemProcessed dipanggil untuk mencatat pesan:

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

Periksa output konsol aplikasi:

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

Menentukan cakupan pesan pencatat

Metode DefineScope(string) membuat Func<TResult> delegasi untuk menentukan cakupan log. DefineScope kelebihan beban mengizinkan meneruskan hingga enam parameter jenis ke string format bernama (templat).

Seperti halnya Define dengan metode , string yang disediakan untuk DefineScope metode adalah templat dan bukan string terinterpolasi. Tempat penampung diisi dalam urutan jenis yang ditentukan. Nama tempat penampung dalam templat harus deskriptif dan konsisten di seluruh templat. Mereka berfungsi sebagai nama properti dalam data log terstruktur. Kami merekomendasikan casing Pascal untuk nama tempat penampung. Misalnya, {Item}, {DateTime}.

Tentukan cakupan log untuk diterapkan ke serangkaian pesan log menggunakan metode .DefineScope Aktifkan IncludeScopes di bagian pencatat konsol appsettings.json:

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

Untuk membuat cakupan log, tambahkan bidang untuk menahan Func<TResult> delegasi untuk cakupan. Aplikasi sampel membuat bidang bernama s_processingWorkScope (Internal/LoggerExtensions.cs):

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

Gunakan DefineScope untuk membuat delegasi. Hingga enam jenis dapat ditentukan untuk digunakan sebagai argumen templat saat delegasi dipanggil. Aplikasi sampel menggunakan templat pesan yang menyertakan waktu tanggal pemrosesan dimulai:

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

Berikan metode ekstensi statis untuk pesan log. Sertakan parameter jenis apa pun untuk properti bernama yang muncul di templat pesan. Aplikasi sampel mengambil DateTime stempel waktu kustom untuk mencatat dan mengembalikan _processingWorkScope:

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

Cakupan membungkus panggilan ekstensi pengelogan dalam blok penggunaan :

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

Periksa pesan log di output konsol aplikasi. Hasil berikut menunjukkan urutan prioritas pesan log dengan pesan cakupan log yang disertakan:

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

Pengoptimalan yang dijaga tingkat log

Pengoptimalan performa lain dapat dilakukan dengan memeriksa LogLevel, dengan ILogger.IsEnabled(LogLevel) sebelum pemanggilan ke metode yang Log* sesuai. Saat pengelogan tidak dikonfigurasi untuk yang diberikan LogLevel, pernyataan berikut ini benar:

  • ILogger.Log tidak dipanggil.
  • Alokasi object[] mewakili parameter dihindari.
  • Tinju jenis nilai dihindari.

Untuk informasi selengkapnya:

Lihat juga