سطح‌های لاگ: کِی Information، کِی Warning و کِی Error

ساعت سه بامداد گوشی کشیک زنگ خورد چون تعداد لاگ‌های Error از آستانه گذشته بود. ده دقیقه طول کشید تا بفهمیم چه شده: یک کاربر چهل بار پشت سر هم رمزش را اشتباه زده بود و هر بار یک LogError ثبت شده بود. سیستم سالم بود؛ فقط سطح لاگ دروغ می‌گفت.

سطح لاگ قراردادی است بین کسی که امروز کد می‌نویسد و کسی که شش ماه بعد، زیر فشار، لاگ را می‌خواند. اگر این قرارداد شل باشد، فیلتر «فقط خطاها» که باید اولین قدم هر عیب‌یابی باشد، پر از نویز می‌شود و آدم‌ها یاد می‌گیرند Errorها را نادیده بگیرند. این مقاله قاعده‌هایی است که در تیم‌هایم برای هر سطح گذاشته‌ام، به‌اضافهٔ هزینهٔ واقعی Debug و نحوهٔ تنظیم سطح برای هر بخش از برنامه. تصویر بزرگ‌تر، یعنی اینکه اصلاً چه چیزی را لاگ کنیم، در راهنمای جامع لاگ‌نویسی در بک‌اند آمده است.

شش سطح با نام‌های مختلف

تقریباً همهٔ کتابخانه‌ها همین شش سطح را دارند، با نام‌های کمی متفاوت. OpenTelemetry هم برای هر کدام یک بازهٔ عددی (SeverityNumber) تعریف کرده که نگاشت بین آن‌ها را استاندارد می‌کند:

نام‌ها مهم نیستند؛ معنا مهم است. و معنا را باید تیم تعریف کند، نه کتابخانه.

قاعدهٔ هر سطح، با مثال

Error: کسی باید کاری بکند

آزمون من یک سؤال است: اگر این خط را ببینم، باید کاری بکنم؟ Error یعنی عملیاتی که از سیستم خواسته شده انجام نشد و سیستم نتوانست خودش جبرانش کند: exception مدیریت‌نشده، پرداختی که بعد از همهٔ تلاش‌های مجدد شکست خورد، داده‌ای که ناسازگار ذخیره شد.

چیزهایی که Error نیستند، هرچند اغلب این‌طور ثبت می‌شوند: خطای اعتبارسنجی ورودی (پاسخ ۴۰۰)، منبعی که پیدا نشد (۴۰۴)، رمز اشتباه، و لغو درخواست توسط خود کاربر (OperationCanceledException وقتی مرورگر را می‌بندد). قاعدهٔ سرانگشتی من: پاسخ‌های ۴xx مشکل سمت کلاینت‌اند و حداکثر Information یا Warning؛ ۵xx مشکل ماست و Error. خطای ۵۰۰ و اینکه چطور از آن به خط کد برسیم را در خطای ۵۰۰ در پروداکشن نوشته‌ام.

Warning: غیرعادی، ولی مدیریت شد

چیزی که نباید رخ می‌داد ولی سیستم از پسش برآمد: تلاش مجددی که بار دوم موفق شد، برگشت به داده‌های کش چون سرویس اصلی جواب نداد، نزدیک شدن به سقف سهمیه، کوئری‌ای که از آستانهٔ زمانی گذشت. آزمون Warning این است: یک بارش مهم نیست، ولی اگر ساعتی صد بار رخ دهد کسی باید نگاه کند.

نمونهٔ رایج، حلقهٔ تلاش مجدد است. توجه کنید که شکست نهایی اینجا لاگ نمی‌شود:

for (var attempt = 1; ; attempt++)
{
    try
    {
        await _gateway.ChargeAsync(order, ct);
        return;
    }
    catch (GatewayTimeoutException ex) when (attempt < MaxAttempts)
    {
        _logger.LogWarning(ex,
            "Gateway {Gateway} timed out for order {OrderId}, attempt {Attempt}/{MaxAttempts}",
            _gateway.Name, order.Id, attempt, MaxAttempts);
        await Task.Delay(TimeSpan.FromSeconds(attempt), ct);
    }
}

در تلاش آخر، شرط when نادرست می‌شود و exception بالا می‌رود تا handler سراسری برنامه آن را یک بار با سطح Error ثبت کند. الگوی «لاگ کن و دوباره throw کن» در هر لایه، یک خطا را پنج بار در لاگ می‌نشاند و شمارش خطاها را بی‌معنا می‌کند. یک exception، یک خط Error.

Information: داستان کاری که سیستم کرد

Information سطح پیش‌فرض پروداکشن است و باید مثل یک دفتر وقایع خوانده شود: برنامه با چه نسخه‌ای بالا آمد، سفارش ثبت شد، پرداخت تأیید شد، جاب شبانه با چند رکورد و در چه مدتی تمام شد. این سطح جای رویدادهای کسب‌وکار و نقطه‌عطف‌های چرخهٔ عمر است، نه جای هر دور حلقه.

دربارهٔ رمز اشتباه: یک بار رمز اشتباه رویداد عادی است و Information کافی است (یا یک رویداد ممیزی امنیتی جدا). ده بار از یک IP در یک دقیقه، Warning است. سطح می‌تواند به الگو بستگی داشته باشد، نه فقط به یک رخداد.

Debug: جزئیات برای کسی که دارد عیب‌یابی می‌کند

تصمیم‌های شاخه‌ای، hit و miss کش، پارامترهای یک فراخوانی بیرونی، اندازهٔ پاسخ‌ها. چیزهایی که برنامه‌نویس هنگام پیدا کردن یک باگ مشخص می‌خواهد ببیند. در پروداکشن به‌طور پیش‌فرض خاموش است.

Trace: ریزترین جزئیات

هر آیتم داخل حلقه، بدنهٔ خام درخواست‌ها، ورود و خروج متدها. تقریباً هرگز در پروداکشن، مگر برای یک بخش کوچک و چند دقیقه.

Critical یا Fatal: برنامه نمی‌تواند ادامه دهد

برنامه بالا نیامد، پیکربندی اجباری وجود ندارد، دیسک پر است و هیچ نوشتنی ممکن نیست. معمولاً آخرین خط پیش از خروج فرایند است. اگر Critical دارید و فرایند هنوز زنده است، احتمالاً سطح اشتباه انتخاب شده.

هزینهٔ Debug در پروداکشن

Debug دو هزینه دارد: وقتی خاموش است و وقتی روشن است. اولی را کمتر کسی می‌بیند.

وقتی خاموش است. متدهای توسعه‌ای مثل LogDebug(string, params object[]) پیش از بررسی سطح، آرایهٔ آرگومان‌ها را می‌سازند و انواع مقداری را box می‌کنند. بدتر از آن، خود عبارت آرگومان همیشه اجرا می‌شود:

// حتی وقتی Debug خاموش است، Serialize هر بار اجرا می‌شود
_logger.LogDebug("Cart contents: {Cart}", JsonSerializer.Serialize(cart));

// درست: کار گران فقط وقتی انجام شود که واقعاً لازم است
if (_logger.IsEnabled(LogLevel.Debug))
{
    _logger.LogDebug("Cart contents: {Cart}", JsonSerializer.Serialize(cart));
}

در مسیرهای پرتکرار، مولد کد [LoggerMessage] این بررسی را خودش پیش از هر کاری انجام می‌دهد و boxing ندارد. اگر پروفایلر شما تخصیص حافظه در متدهای لاگ را نشان می‌دهد، اولین جایی است که باید نگاه کنید.

وقتی روشن است. هزینهٔ اصلی حجم است. یک مثال فرضی ولی واقع‌بینانه: سرویسی با ۲۰۰ درخواست در ثانیه که در هر درخواست ۱۵ خط Debug حدوداً ۴۰۰ بایتی می‌نویسد، روزانه حدود ۱۰۰ گیگابایت لاگ تولید می‌کند. همان سرویس با دو خط Information در هر درخواست، حدود ۱۴ گیگابایت. این تفاوت مستقیماً در دیسک، پهنای باند، هزینهٔ ابزار مدیریت لاگ و سرعت جستجو دیده می‌شود. نحوهٔ برآورد این هزینه در طول زمان را در مدت نگه‌داری لاگ و هزینه توضیح داده‌ام.

و هزینهٔ سومی که در هیچ صورت‌حسابی نمی‌آید: خط‌های Debug معمولاً همان‌هایی‌اند که بدنهٔ درخواست و پارامترها را کامل می‌نویسند، یعنی بیشترین احتمال نشت دادهٔ حساس را دارند.

تنظیم سطح برای هر دسته (category)

راه‌حل این نیست که Debug را همه‌جا روشن یا همه‌جا خاموش کنید. هر logger یک دسته (category) دارد که در ⁦.NET⁩ معمولاً نام کامل کلاسی است که ILogger<T> را گرفته. سطح را می‌شود برای هر پیشوند جدا تنظیم کرد و خاص‌ترین پیشوند برنده است:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning",
      "Microsoft.EntityFrameworkCore.Database.Command": "Warning",
      "MyShop.Payments": "Debug"
    }
  }
}

خط EF Core را عمداً آورده‌ام: Entity Framework Core هر فرمان SQL را در همین دسته با سطح Information می‌نویسد، و در سرویسی پرترافیک همین یک دسته می‌تواند بیشتر حجم لاگ را بسازد. در تنظیمات پیش‌فرض ⁦ASP.NET Core⁩، فایل appsettings.json با تغییر دوباره خوانده می‌شود و تغییر این بخش بدون ری‌استارت اثر می‌کند.

اگر Serilog را جایگزین لاگر پیش‌فرض کرده‌اید، بخش Logging دیگر مرجع نیست و همین کار در بخش Serilog انجام می‌شود:

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft.AspNetCore": "Warning",
        "Microsoft.EntityFrameworkCore.Database.Command": "Warning",
        "MyShop.Payments": "Debug"
      }
    }
  }
}

یا در کد:

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Information()
    .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
    .MinimumLevel.Override("MyShop.Payments", LogEventLevel.Debug)
    .WriteTo.Console()
    .CreateLogger();

یک جزئیات مهم از مستندات Serilog.Settings.Configuration: با بازخوانی فایل، مقدار Default و overrideهای موجود در زمان اجرا به‌روز می‌شوند، ولی افزودن کلید تازه به Override بدون ری‌استارت اثر نمی‌کند. پس اگر می‌خواهید بتوانید یک بخش را در اضطرار روی Debug ببرید، کلیدش را از قبل با مقدار Information در فایل بگذارید. برای تغییر از داخل کد هم LoggingLevelSwitch هست. جزئیات کامل پیکربندی را در Serilog در ⁦ASP.NET Core⁩ آورده‌ام.

در زبان‌های دیگر هم همین ایده هست: در Spring Boot، logging.level.com.myshop.payments=DEBUG؛ در Logback، <logger name="com.myshop.payments" level="DEBUG"/>؛ و در پایتون، logging.getLogger("myshop.payments").setLevel(logging.DEBUG).

قاعده‌هایی که در هر تیم گذاشته‌ام

• Error بدون اقدام، باگ لاگ است. هفته‌ای یک بار فهرست Errorهای تکراری را مرور کنید. هر کدام یا باید رفع شود یا سطحش پایین بیاید. هیچ Errorای نباید «عادی» شود.
• یک exception، یک خط. یا مدیریت کنید و لاگ کنید، یا بالا بفرستید و لاگ نکنید.
• لغو توسط کلاینت Error نیست. در ⁦ASP.NET Core⁩، OperationCanceledException وقتی HttpContext.RequestAborted لغو شده را جدا کنید.
• Debug هدفمند و موقت. فقط برای یک دسته، برای مدت مشخص، و با یادآوری برای خاموش کردنش. Debugهایی که «موقتاً» روشن شدند، معمولاً ماه‌ها روشن می‌مانند.
• سطح بخشی از code review است. همان‌قدر که نام متغیر را بررسی می‌کنید، بپرسید چرا این خط Warning است.
• پیش‌فرض پروداکشن Information؛ فریم‌ورک‌های پرحرف Warning.

وقتی سطح‌ها درست باشند، فیلتر سطح Error واقعاً اولین قدم عیب‌یابی در پروداکشن می‌شود. در LogMug نمودار تعداد لاگ در زمان به تفکیک سطح رسم می‌شود و یک جهش ناگهانی Warning پیش از آنکه به Error برسد به چشم می‌آید، ولی این نمودار هم فقط به اندازهٔ سطح‌هایی که در کد گذاشته‌اید راست می‌گوید. اگر هنوز پیام‌هایتان با string interpolation ساخته می‌شوند، قدم بعدی لاگ ساخت‌یافته است.

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

• لاگ‌نویسی در ⁦C#⁩ و ⁦.NET⁩ (Microsoft Learn) — توضیح رسمی سطح‌ها، دسته‌ها و قواعد فیلتر در appsettings.json.
• شمارشی LogLevel در ⁦.NET⁩ — تعریف دقیق هر سطح از زبان خود مایکروسافت.
• مولد کد LoggerMessage — چطور لاگ پرتکرار را بدون boxing و هزینهٔ اضافه بنویسیم.
• مدل دادهٔ لاگ OpenTelemetry — بازه‌های SeverityNumber و نگاشت سطح‌ها بین کتابخانه‌های مختلف.