ASP.NET Core'da Logging: ILogger, Log Seviyeleri, Structured Logging ve Serilog

Sürüm notu: Bu yazıdaki kodlar .NET 6 ile yazılmıştır ve .NET 10'da da değişmeden çalışır.

Önce Tahmin Et

ProductsController'daki GetById action'ına üç log satırı ekledik:

[HttpGet("{id:int}")]
public ActionResult<Product> GetById(int id)
{
    _logger.LogInformation("Getting product {ProductId}", id);

    Product? product = _store.GetById(id);
    if (product is null)
    {
        _logger.LogWarning("Product {ProductId} not found", id);
        return NotFound();
    }

    _logger.LogDebug("Product {ProductId} found: {ProductName}", id, product.Name);
    return product;
}

appsettings.json template'ten geldiği gibi duruyor:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning"
    }
  },
  "AllowedHosts": "*"
}

/api/products/1 ve /api/products/99 adreslerine birer istek atıyorsun. Konsolda kaç log satırı görürsün ve hangisi hiç görünmez? Bir de mesajdaki {ProductId} neden $"...{id}" diye yazılmadı?

ILogger<T> ve Category

Logger'ı da diğer her şey gibi constructor'dan istersin. Logging altyapısı WebApplication.CreateBuilder tarafından zaten kurulmuş durumda; ekstra bir kayıt gerekmiyor:

[ApiController]
[Route("api/[controller]")]
public class ProductsController : ControllerBase
{
    private readonly IProductStore _store;
    private readonly ILogger<ProductsController> _logger;

    public ProductsController(IProductStore store, ILogger<ProductsController> logger)
    {
        _store = store;
        _logger = logger;
    }
}

İki isteği attığında konsola şunlar düşüyor:

info: ProductCatalog.Controllers.ProductsController[0]
      Getting product 1
info: ProductCatalog.Controllers.ProductsController[0]
      Getting product 99
warn: ProductCatalog.Controllers.ProductsController[0]
      Product 99 not found

Üç satır var, LogDebug ortada yok. Her satırın başında seviye (info, warn), ardından category ve köşeli parantez içinde event id geliyor. ILogger<T>'deki T, category'yi belirler: tipin tam adı, yani ProductCatalog.Controllers.ProductsController. Category sadece bir etiket değil, birazdan göreceğin filtrelerin tutunduğu yer.

Log Seviyeleri

.NET'te altı seviye var, en ayrıntılıdan en ciddiye doğru: Trace (0), Debug (1), Information (2), Warning (3), Error (4), Critical (5). Bir de hiçbir şey yazma demek olan None (6) var. Bir filtre belirli bir seviyeyi açtığında o seviye ve üstündekiler yazılır.

Seviyeyi seçerken kendine şunu sor: bu satırı gece yarısı alarm çalınca okuyan kişi ne görmek ister? Information uygulamanın normal akışını anlatır: bir sipariş oluştu, bir ürün güncellendi. Warning beklenmeyen ama uygulamanın baş edebildiği durumlar içindir; bulunamayan bir ürün buna iyi bir örnek. Error, bir işlemin gerçekten başarısız olduğu yerdir. Critical ise uygulamanın tamamını etkileyen durumlar için, mesela veritabanına hiç ulaşılamaması. Debug ve Trace geliştirme sırasında akışı izlemek içindir ve canlıda genellikle kapalıdır.

Tahmin sorusunun ilk cevabı da bu. "Default": "Information" dediğimiz için Information ve üstü yazıldı, LogDebug filtreye takıldı.

Filtreler: Hangi Log Nereye Akar

Logging:LogLevel altındaki her key bir category önekidir. Bir log için en uzun eşleşen önek kazanır, hiçbiri eşleşmezse Default devreye girer. "Microsoft.AspNetCore": "Warning" satırı bu yüzden önemli; onu Information yaparsan tek bir GET isteği için konsola Request starting, Executing endpoint, Route matched gibi on kadar framework satırı düşer.

Sadece kendi kodumuzun Debug loglarını açmak istersek daha kısa bir önek yeterli. Configuration yazısındaki kuralla, bunu environment variable ile de verebiliriz:

Logging__LogLevel__ProductCatalog=Debug dotnet run

info: ProductCatalog.Controllers.ProductsController[0]
      Getting product 1
dbug: ProductCatalog.Controllers.ProductsController[0]
      Product 1 found: Mechanical Keyboard
info: ProductCatalog.Controllers.ProductsController[0]
      Getting product 99
warn: ProductCatalog.Controllers.ProductsController[0]
      Product 99 not found

ProductCatalog öneki ProductCatalog.Controllers.ProductsController'ı yakaladı, framework logları ise hâlâ Warning'de. Filtreleri provider bazında da verebilirsin. Aşağıdaki ayarda genel seviye Debug, ama Console provider'ı aynı category için yalnızca Warning ve üstünü yazar:

{
  "Logging": {
    "LogLevel": {
      "ProductCatalog": "Debug"
    },
    "Console": {
      "LogLevel": {
        "ProductCatalog": "Warning"
      }
    }
  }
}

Bu, konsolu sakin tutup ayrıntıyı bir dosyaya ya da merkezi bir log sistemine akıtmak istediğinde işe yarar.

Structured Logging: Message Template

Şimdi ikinci soruya gelelim. Aynı logu string interpolation ile yazan bir action ekleyelim:

_logger.LogInformation($"Getting product {id}");

Konsolda iki satır birebir aynı görünür: Getting product 1. Farkı görmek için logları JSON olarak yazdıralım:

builder.Logging.AddJsonConsole(options =>
{
    options.IncludeScopes = true;
    options.JsonWriterOptions = new System.Text.Json.JsonWriterOptions { Indented = true };
});

Message template ile yazılan logun State kısmı:

"State": {
  "Message": "Getting product 1",
  "ProductId": 1,
  "{OriginalFormat}": "Getting product {ProductId}"
}

Interpolation ile yazılanın:

"State": {
  "Message": "Getting product 1",
  "{OriginalFormat}": "Getting product 1"
}

Birincisinde ProductId ayrı bir alan olarak duruyor ve sayı tipinde. Seq, Elasticsearch ya da Application Insights gibi bir sistemde "ProductId = 1 olan bütün logları getir" diyebilirsin. İkincisinde elinde sadece bir metin var; aramak için metin içinde arama yapman gerekir. Üstelik interpolation, log seviyesi kapalı olsa bile string'i her seferinde üretir. Kural basit: log method'larına her zaman sabit bir template ve ayrı argümanlar ver. Template'teki adlar sıraya göre eşleşir, değişken adına göre değil; {ProductId} ilk argümanı alır.

Scope'lar: Bir İşlemin Bütün Loglarını Bağlamak

Bir işlem boyunca yazılan bütün loglara ortak bir bilgi eklemek istediğinde scope açarsın:

[HttpPost]
public ActionResult<Product> Create(Product product)
{
    using (_logger.BeginScope("Creating product {ProductName}", product.Name))
    {
        _logger.LogInformation("Validating price {Price}", product.Price);
        Product created = _store.Add(product);
        _logger.LogInformation("Product saved with id {ProductId}", created.Id);
        return CreatedAtAction(nameof(GetById), new { id = created.Id }, created);
    }
}

JSON console'da IncludeScopes açık olduğu için using bloğunun içindeki her log, scope bilgisini taşır. İkinci logun Scopes listesinden iki element:

{
  "Message": "RequestPath:/api/products RequestId:0HNPPU6FR8L8Q:00000002",
  "RequestId": "0HNPPU6FR8L8Q:00000002",
  "RequestPath": "/api/products"
},
{
  "Message": "Creating product USB-C Hub",
  "ProductName": "USB-C Hub",
  "{OriginalFormat}": "Creating product {ProductName}"
}

Listede bizim scope'umuzun yanında ASP.NET Core'un kendiliğinden açtığı scope'lar da var: TraceId, ConnectionId, RequestId ve çalışan action'ın adı. Aynı anda yüzlerce request işlenirken bir request'e ait satırları bu alanlarla ayıklarsın. Varsayılan konsol formatında scope'lar görünmez; bilgi oradadır ama yazdırılmaz.

LoggerMessage Source Generator

Sık çalışan yollarda her log çağrısı küçük bir bedel öder: argümanlar object'e kutulanır, template her seferinde çözümlenir. .NET 6 ile gelen LoggerMessage source generator bu işi derleme anına taşır:

namespace ProductCatalog.Logging;

public static partial class LogMessages
{
    [LoggerMessage(EventId = 1001, Level = LogLevel.Warning, Message = "Product {ProductId} not found")]
    public static partial void ProductNotFound(ILogger logger, int productId);
}

Method'un gövdesini sen yazmazsın, derleyici üretir. Kullanımı sıradan bir method çağrısı:

LogMessages.ProductNotFound(_logger, id);

warn: ProductCatalog.Controllers.ProductsController[1001]
      Product 99 not found

Köşeli parantezdeki event id artık 0 değil, 1001. Parametre tipi int olarak sabitlendiği için yanlış tipte argüman veremezsin, template ile parametre adları uyuşmazsa da derleme hatası alırsın. Her log için bunu yapmak zorunda değilsin; saniyede binlerce kez çalışan kodda ve ekip içinde standartlaştırmak istediğin mesajlarda kullan.

Serilog'a Geçiş

Yerleşik logging konsol, debug ve event source gibi temel provider'larla gelir; dosyaya yazmak ya da Seq gibi bir sisteme göndermek için bir library gerekir. En yaygın seçenek Serilog. Burada sürüm seçimi önemli: Serilog.AspNetCore 8.0.3, net6.0 hedefini destekleyen son sürüm. 9.0.0 ve 10.0.0 en düşük net8.0 istiyor. 8.0.3 .NET 10 projesinde de sorunsuz çalışıyor; yalnızca .NET 10 hedefleyen bir projede güncel 10.x sürümünü seçebilirsin.

dotnet add package Serilog.AspNetCore --version 8.0.3

using ProductCatalog.Services;
using Serilog;

var builder = WebApplication.CreateBuilder(args);

builder.Host.UseSerilog((context, configuration) => configuration
    .ReadFrom.Configuration(context.Configuration)
    .Enrich.FromLogContext()
    .WriteTo.Console()
    .WriteTo.File("logs/catalog-.log", rollingInterval: RollingInterval.Day));

builder.Services.AddControllers();
builder.Services.AddSingleton<IProductStore, InMemoryProductStore>();

var app = builder.Build();

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

app.Run();

Serilog seviyeleri kendi bölümünden okur, bu yüzden appsettings.json'daki Logging bölümünün yerini şu alır:

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft.AspNetCore": "Warning"
      }
    }
  },
  "AllowedHosts": "*"
}

[00:30:37 INF] Getting product 1
[00:30:37 INF] HTTP GET /api/products/1 responded 200 in 43.8778 ms
[00:30:37 INF] Getting product 99
[00:30:37 WRN] Product 99 not found
[00:30:37 INF] HTTP GET /api/products/99 responded 404 in 1.3335 ms

Controller koduna dokunmadık; aynı ILogger<T> çağrıları artık Serilog'a akıyor. UseSerilogRequestLogging her request için tek ve özet bir satır yazar; framework'ün on satırlık gürültüsünü kapatıp bu satırı tutmak çoğu API için ideal. Dosya sink'i de günlük dosyalar açıyor: logs/catalog-20261104.log. .NET 6'da yerleşik bir HTTP logging middleware'i (AddHttpLogging/UseHttpLogging) da var; header ve body'yi ayrıntılı loglaman gerektiğinde ona bakabilirsin.

Sık Düşülen Tuzaklar

Birincisi, interpolation. Yukarıda gördüğün gibi çalışır ama structured logging'in bütün faydasını çöpe atar. Kod incelemesinde Log...($" gördüğünde dur.

İkincisi, hassas veri loglamak. Şifre, token, kart numarası, kişisel veri log'a girdiğinde log sistemine erişimi olan herkesin eline geçer. Bütün bir request body'sini ya da kullanıcı object'ini loglamadan önce iki kez düşün.

Üçüncüsü, exception'ı yanlış yere koymak. _logger.LogError(ex, "Failed to save product {ProductId}", id) doğru kullanım: exception ilk parametre ve stack trace ile birlikte saklanır. _logger.LogError("Failed: " + ex.Message) stack trace'i kaybeder.

Dördüncüsü, Production'da Default'u Debug'da unutmak. Log hacmi bir anda katlanır, disk ve log sistemi faturası da onunla birlikte. Ayrıntılı seviyeleri yalnızca ihtiyaç duyduğun category için ve geçici olarak aç.

Beşincisi, pahalı argümanlar. _logger.LogDebug("Cart: {Cart}", BuildCartSummary()) satırında Debug kapalı olsa bile BuildCartSummary() çalışır. Böyle durumlarda if (_logger.IsEnabled(LogLevel.Debug)) ile koru ya da LoggerMessage kullan.

Küçük Bir Deneme

★☆☆ Delete action'ına bir LogInformation ekle, ardından command line'dan --Logging:LogLevel:ProductCatalog=Warning vererek uygulamayı başlat. Hangi satırların kaybolduğunu gözle.

★★☆ AddJsonConsole'u aç ve GetById'deki LogDebug'ı görünür kıl. Çıktıda ProductName alanının ayrı bir property olarak geldiğini doğrula. Sonra aynı logu interpolation ile yaz ve farkı karşılaştır.

★★★ LogMessages class'ına ProductCreated adında, Information seviyesinde, ProductId ve ProductName alan bir method ekle. Template'te {ProductName} yazıp parametreyi name diye adlandır ve derleyicinin ne dediğini oku.

Şimdiye kadar bütün örnekler bellekteki bir listeyle çalıştı; uygulama her yeniden başladığında eklediğimiz ürünler kayboldu. Bir sonraki yazıda EF Core ve SQLite ile gerçek bir veri katmanı kuracağız: DbContext kaydı, connection string, ilk migration ve CRUD'u controller'a bağlamak. Bugün açmayı öğrendiğin log seviyeleri, EF Core'un ürettiği SQL'i konsolda görmek için de işine yarayacak.