Serilog در ⁦ASP.NET Core⁩: پیکربندی درست از صفر

Serilog در ASP.NET Core: پیکربندی درست از صفر
در این مقاله می‌خوانید
  1. پکیج‌ها
  2. راه‌اندازی دومرحله‌ای: لاگر bootstrap
  3. پیکربندی در appsettings.json
  4. enricherها: زمینه‌ای که به هر رویداد می‌چسبد
  5. لاگ درخواست‌ها با UseSerilogRequestLogging
  6. sinkها: Console، File و Seq
  7. Console
  8. File
  9. Seq و مقصدهای سازگار
  10. اشتباه‌هایی که در پیکربندی‌ها می‌بینم
  11. منابع و مطالعهٔ بیشتر

بیشتر پیکربندی‌های Serilog که در پروژه‌ها می‌بینم از یک پست وبلاگ قدیمی کپی شده‌اند: کلاس Startup که دیگر وجود ندارد، بخش Logging و بخش Serilog با هم در appsettings.json، چند پکیج که امروز داخل یک پکیج دیگر آمده‌اند، و لاگ درخواست‌ها که یا نیست یا برای هر درخواست پنج خط می‌نویسد. برنامه کار می‌کند، ولی کسی دقیقاً نمی‌داند کدام تنظیم اثر دارد.

در این مقاله Serilog 4 را با Serilog.AspNetCore روی ⁦ASP.NET Core⁩ 8 یا 9 از صفر و تمیز راه می‌اندازم: لاگر دومرحله‌ای، پیکربندی از فایل، enricherها، لاگ درخواست و سه sink رایج. اگر هنوز مطمئن نیستید Serilog لازم دارید یا ILogger خالی به‌اضافهٔ OpenTelemetry کافی است، اول راهنمای جامع لاگ در ⁦ASP.NET Core⁩ را بخوانید؛ آنجا این انتخاب را باز کرده‌ام.

پکیج‌ها

dotnet add package Serilog.AspNetCore
dotnet add package Serilog.Enrichers.Environment
dotnet add package Serilog.Sinks.Seq

Serilog.AspNetCore خودش Serilog، Serilog.Extensions.Hosting، Serilog.Settings.Configuration، Serilog.Formatting.Compact و sinkهای Console و File و Debug را می‌آورد؛ لازم نیست جدا نصبشان کنید. توصیهٔ خود پروژه این است که نسخهٔ اصلی Serilog.AspNetCore را هم‌راستا با نسخهٔ ⁦.NET⁩ برنامه انتخاب کنید. دو پکیج دیگر فقط برای enricherهای محیط و ارسال به Seq یا مقصدهای سازگار با آن لازم‌اند.

راه‌اندازی دومرحله‌ای: لاگر bootstrap

مشکلی که این الگو حل می‌کند: اگر لاگر را فقط از appsettings.json بسازید، هر خطایی که پیش از ساخته شدن host رخ دهد (فایل پیکربندی خراب، سرویسی که در DI ثبت نشده، رشتهٔ اتصال غلط) جایی ثبت نمی‌شود. برنامه بالا نمی‌آید و شما هیچ ردی ندارید. این دقیقاً همان لحظه‌ای است که بیشترین نیاز را به لاگ دارید.

راه‌حل Serilog این است که یک لاگر ساده و فوری بسازید که بعداً با لاگر کامل جایگزین می‌شود:

using Serilog;
using Serilog.Events;

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
    .Enrich.FromLogContext()
    .WriteTo.Console()
    .CreateBootstrapLogger();

try
{
    Log.Information("Starting up");

    var builder = WebApplication.CreateBuilder(args);

    builder.Services.AddSerilog((services, lc) => lc
        .ReadFrom.Configuration(builder.Configuration)
        .ReadFrom.Services(services)
        .Enrich.FromLogContext()
        .Enrich.WithProperty("Environment", builder.Environment.EnvironmentName));

    builder.Services.AddControllers();

    var app = builder.Build();

    app.UseSerilogRequestLogging();
    app.MapControllers();

    app.Run();
}
catch (Exception ex) when (ex is not HostAbortedException)
{
    Log.Fatal(ex, "Application terminated unexpectedly");
}
finally
{
    Log.CloseAndFlush();
}

چند نکته در همین چند خط:

  • لاگر نهایی، لاگر bootstrap را کاملاً جایگزین می‌کند. هیچ sinkای از مرحلهٔ اول به ارث نمی‌رسد؛ اگر کنسول را در هر دو مرحله می‌خواهید، باید در هر دو جا تعریفش کنید (اینجا در فایل پیکربندی).
  • AddSerilog یا UseSerilog. builder.Host.UseSerilog(...) هنوز کار می‌کند و در پروژه‌های قدیمی‌تر زیاد می‌بینیدش؛ builder.Services.AddSerilog(...) شکل جدیدتر و مستقیم روی IServiceCollection است. هر دو همان کار را می‌کنند؛ یکی را انتخاب کنید.
  • HostAbortedException. ابزارهایی مثل dotnet ef برنامه را اجرا می‌کنند و عمداً با این exception متوقفش می‌کنند. بدون این فیلتر، هر migration یک لاگ Fatal بی‌معنا می‌سازد.
  • CloseAndFlush در finally. sinkهای شبکه‌ای مثل Seq رویدادها را دسته‌ای می‌فرستند. بدون این خط، آخرین رویدادها، یعنی همان‌هایی که علت توقف را می‌گویند، ممکن است هرگز نرسند.

و بخش Logging را از appsettings.json حذف کنید. وقتی Serilog لاگر را جایگزین کرده، آن بخش عملاً مرجع نیست و فقط کسی را که بعداً می‌آید گیج می‌کند.

پیکربندی در appsettings.json

کد را حداقلی نگه می‌دارم و هر چیزی که ممکن است بین محیط‌ها فرق کند را در فایل می‌گذارم:

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File", "Serilog.Sinks.Seq", "Serilog.Enrichers.Environment" ],
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft.AspNetCore": "Warning",
        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
      }
    },
    "Enrich": [ "FromLogContext", "WithMachineName" ],
    "Properties": {
      "Application": "orders-api"
    },
    "WriteTo": [
      { "Name": "Console" },
      {
        "Name": "File",
        "Args": {
          "path": "logs/orders-.log",
          "rollingInterval": "Day",
          "rollOnFileSizeLimit": true,
          "retainedFileCountLimit": 14,
          "formatter": "Serilog.Formatting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact"
        }
      },
      {
        "Name": "Seq",
        "Args": {
          "serverUrl": "https://ingest.logmug.ir",
          "apiKey": ""
        }
      }
    ]
  }
}

بخش Using در پروژه‌های ⁦.NET⁩ معمولاً لازم نیست، چون Serilog.Settings.Configuration پکیج‌هایی را که «Serilog» در نامشان دارند خودش پیدا می‌کند. ولی در انتشار تک‌فایلی (single-file) این کشف خودکار کار نمی‌کند، پس من همیشه صریح می‌نویسمش؛ هزینه‌ای ندارد و یک دسته خطای عجیب را حذف می‌کند.

کلید API را هرگز در فایلی که در مخزن کد است ننویسید. چون WriteTo آرایه است، مقدار را می‌شود با متغیر محیطی بر اساس اندیس داد: Serilog__WriteTo__2__Args__apiKey. فقط حواستان باشد که اگر ترتیب sinkها عوض شود، این اندیس هم باید عوض شود.

تنظیم MinimumLevel و overrideها، و اینکه کدام‌شان بدون ری‌استارت عوض می‌شوند، موضوع مقالهٔ سطح‌های لاگ است و اینجا تکرارش نمی‌کنم.

enricherها: زمینه‌ای که به هر رویداد می‌چسبد

enricher به هر رویداد ویژگی اضافه می‌کند، بی آنکه در هر فراخوانی لاگ تکرارش کنید. سه موردی که همیشه دارم:

  • FromLogContext — بدون آن، ویژگی‌هایی که با LogContext.PushProperty یا ILogger.BeginScope اضافه می‌کنید بی‌صدا ناپدید می‌شوند. فراموش کردنش رایج‌ترین دلیل «چرا scope من در لاگ نیست؟» است.
  • WithMachineName از Serilog.Enrichers.Environment — ویژگی MachineName را اضافه می‌کند. وقتی سه نمونه از سرویس پشت load balancer دارید، اولین سؤال هر حادثه این است که خطا روی کدام سرور بوده.
  • نام سرویس و محیط — Application را در Properties گذاشتم و Environment را در کد از builder.Environment خواندم. همین پکیج WithEnvironmentName() هم دارد که از ASPNETCORE_ENVIRONMENT یا DOTNET_ENVIRONMENT می‌خواند (و اگر هیچ‌کدام نباشد Production می‌گذارد)، ولی نام ویژگی‌اش EnvironmentName است. اگر مقصد لاگ شما نام دیگری انتظار دارد، صریح نوشتن ساده‌تر است.

برای ویژگی‌هایی که فقط در بخشی از کد معنا دارند:

using (_logger.BeginScope(new Dictionary<string, object>
{
    ["OrderId"] = order.Id,
    ["TenantId"] = tenant.Id
}))
{
    // همهٔ لاگ‌های این بلوک OrderId و TenantId را دارند
    await _fulfillment.ProcessAsync(order, ct);
}

لاگ درخواست‌ها با UseSerilogRequestLogging

⁦ASP.NET Core⁩ به‌طور پیش‌فرض برای هر درخواست چند رویداد جدا می‌نویسد: شروع درخواست، اجرای endpoint، پایان اجرا، پایان درخواست. middleware خود Serilog همهٔ این‌ها را در یک رویداد خلاصه می‌کند که روش، مسیر، کد وضعیت و زمان را دارد:

HTTP GET /orders/42 responded 200 in 35.2140 ms

برای اینکه رویدادهای تکراری فریم‌ورک حذف شوند، دستهٔ Microsoft.AspNetCore را روی Warning بگذارید (که در فایل بالا گذاشتیم). جای middleware مهم است: هر چیزی که پیش از آن در pipeline بیاید لاگ نمی‌شود. اگر UseStaticFiles() دارید، آن را قبل بگذارید تا درخواست‌های فایل ایستا لاگ را پر نکنند.

تنظیم سطح و افزودن ویژگی به همین رویداد هم ممکن است. نسخه‌ای که در بیشتر پروژه‌ها می‌گذارم:

app.UseSerilogRequestLogging(options =>
{
    options.GetLevel = (httpContext, elapsedMs, ex) =>
        ex != null || httpContext.Response.StatusCode >= 500 ? LogEventLevel.Error
        : httpContext.Request.Path.StartsWithSegments("/health") ? LogEventLevel.Verbose
        : elapsedMs > 2000 ? LogEventLevel.Warning
        : LogEventLevel.Information;

    options.EnrichDiagnosticContext = (diagnosticContext, httpContext) =>
    {
        diagnosticContext.Set("UserId", httpContext.User.FindFirst("sub")?.Value);
    };
});

health check با سطح Verbose عملاً حذف می‌شود، درخواست کند Warning می‌شود و خطای سرور Error. در کنترلرها هم می‌توانید IDiagnosticContext را تزریق کنید و با Set ویژگی‌هایی مثل شناسهٔ سفارش را به همین رویداد پایانی بچسبانید؛ یک رویداد غنی بهتر از پنج رویداد فقیر است.

یک چیز رایگان هم هست: از Serilog 3.1 به بعد، شناسهٔ trace و span از Activity.Current خودکار روی هر رویداد ثبت می‌شود و ⁦ASP.NET Core⁩ برای هر درخواست یک Activity می‌سازد. یعنی همهٔ خط‌های یک درخواست، بدون کد اضافه، یک trace_id مشترک دارند. اینکه با این شناسه چطور یک درخواست را در چند سرویس دنبال کنید، در trace_id و correlation id آمده است.

sinkها: Console، File و Seq

Console

در کانتینر، stdout مسیر استاندارد لاگ است و ابزار جمع‌آوری همان را می‌خواند. در توسعه قالب متنی پیش‌فرض خواناست؛ افزودن {SourceContext} به outputTemplate کمک می‌کند بفهمید یک خط پرحرف از کدام کلاس می‌آید. در پروداکشن کانتینری، formatter فشردهٔ JSON را به کنسول بدهید.

File

دو پیش‌فرض این sink را بدانید: حداکثر ۳۱ فایل نگه می‌دارد، و هر فایل را به ۱ گیگابایت محدود می‌کند. نکتهٔ دوم غافلگیرکننده است: وقتی فایل به سقف برسد، تا نقطهٔ چرخش بعدی هیچ رویدادی نوشته نمی‌شود، مگر اینکه rollOnFileSizeLimit را روشن کنید. روی IIS هم مسیر را جایی بگذارید که هویت application pool اجازهٔ نوشتن داشته باشد. و یادتان باشد فایل روی دیسک سرور، با هر قالبی، هنوز یعنی SSH و grep روی تک‌تک سرورها.

Seq و مقصدهای سازگار

Serilog.Sinks.Seq رویدادها را دسته‌ای و با HTTP در قالب CLEF می‌فرستد. Seq خودش ابزار پخته و خوبی است، به‌خصوص برای تیم‌های ⁦.NET⁩ که سرور خودشان را دارند. همین پروتکل را مقصدهای دیگر هم پیاده کرده‌اند؛ مثلاً LogMug همان را می‌پذیرد و برنامه بدون هیچ پکیج اختصاصی، فقط با عوض کردن نشانی و کلید وصل می‌شود:

.WriteTo.Seq("https://ingest.logmug.ir", apiKey: "lm_ingest_...")

مراحل کامل، از ساخت کلید تا دیدن اولین لاگ، در راهنمای اتصال برنامه‌های Serilog آمده است. این sink خودش دسته‌ای و غیرهمزمان کار می‌کند، پس پیچیدن آن در WriteTo.Async لازم نیست. اگر ارتباط سرور با مقصد ناپایدار است، پارامتر bufferBaseFilename رویدادها را اول روی دیسک می‌نویسد و بعد می‌فرستد تا قطعی‌های کوتاه چیزی را از بین نبرند.

اشتباه‌هایی که در پیکربندی‌ها می‌بینم

  1. دو بخش Logging و Serilog با هم، و تیمی که سطح را در اولی عوض می‌کند و تعجب می‌کند چرا اثری ندارد.
  2. string interpolation در فراخوانی لاگ. Serilog را نصب کرده‌اند ولی همه را به متن ساده تبدیل می‌کنند. چرایی‌اش در لاگ ساخت‌یافته.
  3. نبودن Enrich.FromLogContext() و scopeهایی که ناپدید می‌شوند.
  4. {@Request} یا {@Model} که کل بدنهٔ درخواست، از جمله رمز و توکن، را در لاگ می‌ریزد. فهرست چیزهایی که نباید لاگ شوند در دادهٔ حساس در لاگ آمده است.
  5. نبودن Log.CloseAndFlush() و گم شدن آخرین لاگ‌ها در هر ری‌استارت.

اگر برنامه‌ای که دارید هنوز روی ⁦.NET Framework⁩ است، تقریباً همهٔ این‌ها آنجا هم صدق می‌کند، با چند تفاوت در محل راه‌اندازی؛ آن را در لاگ متمرکز برای برنامه‌های ⁦.NET Framework⁩ نوشته‌ام.

منابع و مطالعهٔ بیشتر

لاگ همهٔ سرویس‌هایتان را در یک جا جستجو کنید

C#، Java یا هر زبان دیگر — با چند خط پیکربندی وصل می‌شود. پلن رایگان کارت بانکی نمی‌خواهد.

شروع رایگان