EF Core'da Connection Resiliency, Logging ve Diagnostics: Execution Strategy, Command Timeout, TagWith, Event'ler ve Metric'ler

Sürüm notu: Bu yazıdaki kodlar EF Core (Entity Framework Core) 10, SQL Server 2025 ve OpenTelemetry .NET 1.21 ile yazılıp denenmiştir.

Önce Tahmin Et

Sitedeki serilerin ortak örnek uygulaması Bookstore'un (bir online kitapçı) API'sinde EnableRetryOnFailure() açık. Bir failover'ı taklit etmek için veritabanını ALTER DATABASE ... SET OFFLINE WITH ROLLBACK IMMEDIATE ile kapatıyorsun, hemen ardından POST /orders ile bir sipariş gönderiyorsun ve yedi saniye sonra veritabanını SET ONLINE ile geri açıyorsun. Sipariş kaydedilir mi, log'da kaç tane "retry" satırı görürsün?

Ben ilk denemede şunu aldım: sipariş 10,2 saniyede 201 ile kaydedildi, log'da tek bir retry satırı yoktu. EF Core'un execution strategy'si devreye bile girmemişti. Nedeni bu yazının ikinci bölümünde.

Bu yazı Bookstore API'sinin veritabanıyla konuşurken karşılaştığı kötü günlere ayrılmış: kopan connection'lar, uzayan sorgular ve "bu SQL'i hangi endpoint attı?" sorusu. 13. yazıda execution strategy'ye bir tuzak olarak değinmiş, 17 ve 21. yazılarda LogTo, TagWith ve yavaş sorgu interceptor'ını kurmuştuk. Burada hepsini production'a hazır bir API'de bir araya getiriyoruz.

EnableRetryOnFailure ve Execution Strategy

builder.Services.AddDbContext<BookstoreContext>(options =>
{
    options.UseSqlServer(builder.Configuration.GetConnectionString("Bookstore"), sql =>
    {
        sql.EnableRetryOnFailure(maxRetryCount: 5, maxRetryDelay: TimeSpan.FromSeconds(10), errorNumbersToAdd: null);
        sql.CommandTimeout(15);
    });
    options.ConfigureWarnings(w => w.Throw(CoreEventId.RowLimitingOperationWithoutOrderByWarning));
    if (builder.Environment.IsDevelopment())
    {
        options.EnableSensitiveDataLogging().EnableDetailedErrors();
    }
});

EnableRetryOnFailure(), SQL Server provider'ının SqlServerRetryingExecutionStrategy'sini açıyor. Parametresiz çağrının varsayılanları, EF Core kaynak kodunda 6 deneme ve en fazla 30 saniye bekleme. Ben bir API isteği için 30 saniyeyi uzun bulduğum için 5 deneme ve 10 saniyeyle sınırladım. Bekleme süresi her denemede katlanarak artıyor ve araya rastgele bir pay ekleniyor; aşağıdaki çıktıda göreceğin gibi.

Strategy her hatayı tekrar denemiyor; yalnız geçici (transient) olduğunu bildiği SQL Server hata numaralarını. Liste EF Core'un SqlServerTransientExceptionDetector class'ında: deadlock (1205), "Cannot open database" (4060), bağlantı kopmaları (10053, 10054, 10060), Azure SQL'in "veritabanı şu an kullanılamıyor" kodları (40613, 40501…) ve daha fazlası. Senin ortamına özgü bir hata numarası varsa errorNumbersToAdd ile ekliyorsun. Bir şey listede yok: komut timeout'u (-2). Kaynak koddaki yorum nedenini söylüyor: timeout geldiğinde komut aslında tamamlanmış olabilir, tekrar denemek güvenli değil.

Retry açıkken EF Core sorgu sonuçlarını belleğe tamponluyor (buffering), çünkü yarıda kopan bir okumayı baştan alabilmesi gerekiyor. Çok büyük sonuç setleri döndüren sorgularda bellek kullanımı artar; bunu bilerek aç.

Failover'ı Denemek

İlk denemede retry log'u çıkmamasının nedeni, EF Core'un altındaki Microsoft.Data.SqlClient'ın kendi bağlantı dayanıklılığı. Havuzdaki connection koptuğunda SqlClient onu kendi kendine yeniden kurmayı deniyor (ConnectRetryCount varsayılan olarak 1, ConnectRetryInterval 10 saniye); isteğin 10,2 saniye sürmesi tam bu bekleme. Hata EF Core'a hiç ulaşmadı. Microsoft'un connection resiliency dokümanı da örnek connection string'inde ConnectRetryCount=0 kullanıyor; iki katmanın aynı işi üst üste yapmaması için retry'ı tek yerde topla. Connection string'e ConnectRetryCount=0 ekleyip aynı denemeyi tekrarladım:

01:26:15  ALTER DATABASE ... SET OFFLINE WITH ROLLBACK IMMEDIATE
01:26:22  ALTER DATABASE ... SET ONLINE

info: Microsoft.EntityFrameworkCore.Infrastructure[10404]
      A transient exception occurred during execution. The operation will be retried after 0ms.
      Microsoft.Data.SqlClient.SqlException (0x80131904): Cannot open database "efseries_ext_33" requested by the login. The login failed.
info: Microsoft.EntityFrameworkCore.Infrastructure[10404]
      A transient exception occurred during execution. The operation will be retried after 1048ms.
info: Microsoft.EntityFrameworkCore.Infrastructure[10404]
      A transient exception occurred during execution. The operation will be retried after 3078ms.
info: Microsoft.EntityFrameworkCore.Infrastructure[10404]
      A transient exception occurred during execution. The operation will be retried after 7615ms.
info: Bookstore.Api.Orders.PlaceOrderRequest[0]
      Order 100009 placed for request 6f1d2c3a-0000-4000-8000-000000000003

{"id":9,"orderNumber":100009,"totalAmount":14.89} http=201 t=12.172230s

Çıktıyı okunur olsun diye JSON log'dan düz metne çevirdim ve her retry'ın stack trace'ini kestim. Dört deneme başarısız oldu, beşinci denemede veritabanı açıktı ve sipariş kaydedildi; müşteri bir hata görmedi, yalnız 12 saniye bekledi. Bekleme süreleri 0, 1, 3, 7,6 saniye: katlanan bekleme ve rastgele pay. Gerçek bir failover'ı (availability group'un diğer replikaya geçmesi gibi) Veritabanı Performansı ve Scaling serisinin "High Availability ve Failover" yazısında anlattık; uygulamanın ondan sağ çıkması tam olarak bu ayara bağlı.

Kendi Transaction'ın ve Idempotency

13. yazıda gördüğümüz kural burada da geçerli: retry açıkken BeginTransactionAsync ile kendi transaction'ını açıp SaveChanges çağırırsan EF Core "The configured execution strategy 'SqlServerRetryingExecutionStrategy' does not support user-initiated transactions" diye InvalidOperationException fırlatıyor; bu kurulumda da birebir aynı mesajı aldım. Çözüm, bütün işi strategy'ye teslim etmek. Ama bir zor durum daha var: connection tam COMMIT sırasında koparsa transaction'ın commit olup olmadığını bilemezsin. Strategy olmadığını varsayıp tekrar dener; olduysa sipariş iki kez yazılır.

Bookstore'da buna karşı iki önlem aldım. Birincisi, istemci her siparişe bir RequestId (GUID) veriyor ve tablo bu kolonda unique index taşıyor; aynı sipariş ikinci kez yazılmak istenirse veritabanı reddediyor. İkincisi, EF Core'un ExecuteInTransactionAsync'i: commit sırasında geçici bir hata olursa verifySucceeded fonksiyonunu çağırıp işin aslında olup olmadığını soruyor:

// Aynı RequestId tekrar geldiyse (istemci retry'ı) var olan siparişi dön.
var existing = await db.Orders
    .TagWith("POST /orders: idempotency check")
    .Where(o => o.RequestId == request.RequestId)
    .Select(o => new { o.Id, o.OrderNumber, o.TotalAmount })
    .FirstOrDefaultAsync(ct);
if (existing is not null)
{
    return Results.Ok(existing);
}

// ... fiyatları oku, Order ve OrderItem'ları kur, db.Orders.Add(order)

var strategy = db.Database.CreateExecutionStrategy();
await strategy.ExecuteInTransactionAsync(
    db,
    operation: (context, token) => context.SaveChangesAsync(acceptAllChangesOnSuccess: false, token),
    verifySucceeded: (context, token) => context.Orders.AsNoTracking().AnyAsync(o => o.RequestId == request.RequestId, token),
    ct);
db.ChangeTracker.AcceptAllChanges();

acceptAllChangesOnSuccess: false önemli: işlem tekrar denenirse change tracker'daki entity'ler hâlâ Added durumunda olmalı. Her şey bittikten sonra AcceptAllChanges ile durumu kapatıyoruz. Aynı RequestId ile ikinci kez gönderdiğim istek yeni sipariş açmadı, ilkini döndürdü:

{"id":7,"orderNumber":100007,"totalAmount":41.99}
{"id":7,"orderNumber":100007,"totalAmount":41.99}

Commit anında kopma durumunu yerelde güvenilir şekilde üretemedim, bu yüzden verifySucceeded'ın çağrıldığı anı göstermiyorum. Ama mantığı basit: kontrolün kendisi bir sorgu ve o da strategy'nin içinde çalışıyor; veritabanı gelince "bu RequestId var mı?" diye soruyor. Çözüm Desenleri serisinin "Idempotency Key" yazısında tasarımını konuştuğumuz yaklaşımın EF Core tarafındaki karşılığı bu.

Command Timeout

SQL Server provider'ında komut timeout'u varsayılan olarak 30 saniye. Bir web isteğinde 30 saniye bekleyen kullanıcı çoktan gitmiştir, ben API'de sql.CommandTimeout(15) ile 15'e indirdim; log satırlarındaki CommandTimeout='15' bunu gösteriyor. Tek bir işlem için db.Database.SetCommandTimeout(...) kullanılabiliyor. Bir rapor işinde timeout'u 2 saniyeye indirip 5 saniye süren bir komut çalıştırdım:

db.Database.SetCommandTimeout(TimeSpan.FromSeconds(2));
await db.Database.ExecuteSqlRawAsync("WAITFOR DELAY '00:00:05'");

fail: 11/15/2026 01:26:59.596 RelationalEventId.CommandError[20102] (Microsoft.EntityFrameworkCore.Database.Command)
      Failed executing DbCommand (2,014ms) [Parameters=[], CommandType='Text', CommandTimeout='2']
      WAITFOR DELAY '00:00:05'
SqlException: Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
Number: -2

Retry açık olmasına rağmen tek bir retry satırı yok; yukarıda söylediğimiz gibi -2 tekrar denenmiyor. Timeout'u yükseltmek yavaş sorguyu düzeltmez; önce 17. ve 30. yazılardaki gibi sorguyu ve index'i incele.

Logging: Kategoriler, Ortamlar ve Uyarıyı Hataya Çevirmek

ASP.NET Core'da AddDbContext ile kaydedilen context, uygulamanın ILoggerFactory'sini kendiliğinden kullanıyor; LogTo'ya gerek yok. LogTo console uygulamaları, testler ve hızlı bir bakış için. Neyin loglanacağını kategoriyle seçiyorsun. EF Core'un en çok işe yarayan kategorisi, çalışan her SQL'i yazan Microsoft.EntityFrameworkCore.Database.Command:

// appsettings.json
"Microsoft.EntityFrameworkCore.Database.Command": "Warning"

// appsettings.Development.json
"Microsoft.EntityFrameworkCore.Database.Command": "Information"

Aynı isteği iki ortamda çalıştırıp saydım: Production'da 0, Development'ta 1 komut log'u. Production'da Warning seviyesi yine de hatalı komutları (CommandError) yazıyor. Belirli bir event'i hedeflemek istersen LogTo(Console.WriteLine, [RelationalEventId.CommandExecuted]) gibi EventId listesi verebilirsin; yukarıdaki timeout örneğinde yalnız ExecutionStrategyRetrying ve CommandError event'lerini böyle seçtim.

EnableSensitiveDataLogging parametre değerlerini log'a yazıyor (@q_contains='%emma%'); EnableDetailedErrors ise okuma hatalarında hangi kolonun sorun çıkardığını söyleyen daha pahalı kontroller ekliyor. İkisini de yalnız Development'ta açtım. EF Core bunu ilk istekte bir uyarıyla hatırlatıyor: "Sensitive data logging is enabled. Log entries and exception messages may include sensitive application data; this mode should only be enabled during development."

ConfigureWarnings ile bir uyarıyı hataya çevirebiliyorsun. 09. yazıda OrderBy'sız Take'in yalnız uyarı ürettiğini görmüştük; API'de bunu hata yaptım ve OrderBy'sız bir test endpoint'i 500 döndü:

System.InvalidOperationException: An error was generated for warning 'Microsoft.EntityFrameworkCore.Query.RowLimitingOperationWithoutOrderByWarning': The query uses a row limiting operator ('Skip'/'Take') without an 'OrderBy' operator. This may lead to unpredictable results. ...

Uyarılar log'da kaybolur, exception'lar testte yakalanır. Ekipçe "bunu bir daha görmek istemiyoruz" dediğiniz uyarıları hataya çevirmek ucuz bir kalite kapısı.

TagWith ve TagWithCallSite: SQL'i Koda Bağlamak

17. yazıda TagWith ile sorguya elle etiket koymuştuk. EF Core 6 ile gelen TagWithCallSite() etiketi kendisi üretiyor: dosya adı ve satır numarası. API'de arama endpoint'ine ekledim ve log'u JSON olarak, scope'larıyla birlikte yazdırdım (builder.Logging.AddJsonConsole(o => o.IncludeScopes = true)). Kısaltılmış hâli:

{
  "EventId": 20101,
  "LogLevel": "Information",
  "Category": "Microsoft.EntityFrameworkCore.Database.Command",
  "Message": "Executed DbCommand (15ms) [Parameters=[@p='20', @q_contains='%emma%' (Size = 200), @q_contains0='%emma%' (Size = 100)], CommandType='Text', CommandTimeout='15']\n-- File: .../src/Bookstore.Api/Program.cs:51\n\nSELECT TOP(@p) [b].[Id], [b].[Title], [a].[Name] AS [Author], [b].[Price]\nFROM [catalog].[Books] AS [b]\n...",
  "Scopes": [
    {
      "Message": "SpanId:70a6f028ddcc0098, TraceId:dde5b2c6ccb84fe2df3821ca90f320d0, ParentId:0000000000000000",
      "TraceId": "dde5b2c6ccb84fe2df3821ca90f320d0"
    },
    {
      "Message": "RequestPath:/books/search RequestId:0HNQ2JQJT12MV:00000001",
      "RequestPath": "/books/search"
    }
  ]
}

Dosya yolunu ben kısalttım; gerçekte build makinesindeki tam yol yazıyor. Tek bir log kaydında üç bilgi birleşiyor: SQL'in kendisi, onu üreten kod satırı (Program.cs:51) ve isteğin yolu (RequestPath) ile TraceId'si. .NET'te Logging serisinin Seq yazısındaki kurulumla bu event'ler Seq'e gittiğinde RequestPath = '/books/search' filtresi o endpoint'in attığı bütün sorguları, TraceId da tek bir isteğin bütün sorgularını getiriyor. Etiket SQL metninin parçası olduğu için veritabanına giden batch'te de duruyor; SQL Server'da batch metnini yakalayan Extended Events gibi araçlarda da görünür. Elle verilen etiket (TagWith("GET /books/bestsellers")) refactoring'de değişmiyor; TagWithCallSite ise her zaman doğru satırı söylüyor ama satır kaydıkça değişiyor. Ben endpoint adını taşıyan elle etiketleri tercih ediyorum.

DiagnosticListener, OpenTelemetry ve Metric'ler

21. yazıda yavaş sorguları bir DbCommandInterceptor ile yakalamıştık. Interceptor context'e bağlı; bütün context'leri tek yerden dinlemek için EF Core'un DiagnosticListener'ı da var. Interceptor'dan farkı, akışa müdahale edememesi; yalnız izliyor:

// EF Core'un DiagnosticListener'ını dinler, eşikten yavaş komutları loglar.
public sealed class SlowCommandObserver(ILogger<SlowCommandObserver> logger, TimeSpan threshold)
    : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object?>>
{
    public void OnNext(DiagnosticListener listener)
    {
        if (listener.Name == DbLoggerCategory.Name)
        {
            listener.Subscribe(this);
        }
    }

    public void OnNext(KeyValuePair<string, object?> e)
    {
        if (e.Key == RelationalEventId.CommandExecuted.Name
            && e.Value is CommandExecutedEventData data
            && data.Duration > threshold)
        {
            logger.LogWarning("Slow command ({ElapsedMs} ms): {CommandText}", (long)data.Duration.TotalMilliseconds, data.Command.CommandText);
        }
    }

    public void OnCompleted() { }
    public void OnError(Exception error) { }
}

Eşik varsayılan olarak 200 ms; denemek için Diagnostics:SlowCommandMs ayarıyla 5 ms'ye indirdim ve best seller endpoint'i şu uyarıyı üretti; log'un scope'unda RequestPath /books/bestsellers:

Slow command (15 ms): -- GET /books/bestsellers

SELECT TOP(@p2) [b].[Title], [f].[Units]
FROM [dbo].[fn_BestSellers](@since) AS [f]
INNER JOIN [catalog].[Books] AS [b] ON [f].[BookId] = [b].[Id]
ORDER BY [f].[Units] DESC

Log'dan bir adım ötesi trace. OpenTelemetry'nin (OTel; telemetri verisini üretmek ve taşımak için açık standart) EF Core instrumentation paketi (OpenTelemetry.Instrumentation.EntityFrameworkCore, hâlâ beta: 1.21.0-beta.1) her komut için bir span açıyor. Denemek için console exporter'ı bir ayarın arkasına koydum:

builder.Services.AddOpenTelemetry()
    .ConfigureResource(r => r.AddService("Bookstore.Api"))
    .WithTracing(t => t.AddAspNetCoreInstrumentation().AddEntityFrameworkCoreInstrumentation().AddConsoleExporter())
    .WithMetrics(m => m.AddMeter("Microsoft.EntityFrameworkCore").AddConsoleExporter());

Activity.TraceId:            75d4a2db6b18ff367b0b7f5d1ecf5f18
Activity.SpanId:             af8e5718de7239d0
Activity.ParentSpanId:       3aaff3aab184699a
Activity.DisplayName:        efseries_ext_33
Activity.Kind:               Client
Activity.Duration:           00:00:00.0288600
Activity.Tags:
    db.system: mssql
    db.name: efseries_ext_33
    db.statement:

SELECT TOP(@p2) [b].[Title], [f].[Units]
FROM [dbo].[fn_BestSellers](@since) AS [f]
...

SQL span'inin parent'ı, GET /books/bestsellers adlı ASP.NET Core span'i; ikisi aynı TraceId'yi taşıyor. Dikkatimi çeken bir ayrıntı: db.statement'ta TagWith yorumu yoktu, yerinde boş satırlar vardı; aynı komut log'da ve DiagnosticListener'da etiketle birlikte görünüyordu. Etikete trace'ten bakmayı planlıyorsan önce kendi kurulumunda dene. Trace'leri Jaeger ya da Tempo'ya göndermek ve dashboard kurmak Observability serisinin konusu.

EF Core 9'dan beri Microsoft.EntityFrameworkCore adlı bir meter de var: aktif context sayısı, sorgu sayısı, compiled query cache hit/miss, SaveChanges sayısı, execution strategy hataları ve concurrency hataları. Uygulamaya dokunmadan dotnet-counters ile görülebiliyor; API'ye yük verirken topladım:

dotnet-counters collect -p <PID> --counters Microsoft.EntityFrameworkCore --duration 00:00:00:06 --format csv

Microsoft.EntityFrameworkCore,microsoft.entityframeworkcore.queries ({query} / 1 sec),Rate,14
Microsoft.EntityFrameworkCore,microsoft.entityframeworkcore.compiled_query_cache_hits ({hits} / 1 sec),Rate,14
Microsoft.EntityFrameworkCore,microsoft.entityframeworkcore.compiled_query_cache_misses ({misses} / 1 sec),Rate,0
Microsoft.EntityFrameworkCore,microsoft.entityframeworkcore.execution_strategy_operation_failures ({failure} / 1 sec),Rate,0
Microsoft.EntityFrameworkCore,microsoft.entityframeworkcore.active_dbcontexts ({dbcontext}),Metric,0

Saniyede 14 sorgu, 14'ü de compiled query cache'ten: her sorgu ilk seferden sonra tekrar derlenmiyor. Cache miss'in sürekli sıfırdan büyük kalması, her seferinde farklı bir expression tree üreten dinamik sorguların işareti. execution_strategy_operation_failures dokümana göre retry'lı bir işlemdeki her başarısız denemeyi sayıyor; sıfırdan çıkması altyapıda geçici sorunlar olduğunu söylüyor. dotnet-counters'ın genel kullanımı .NET'te Profiling ve Diagnostics serisinin "dotnet-counters ve Built-in Metric'ler" yazısında.

Sık Düşülen Tuzaklar

Birincisi, retry açıkken elle BeginTransaction açmak. Hata hemen gelir ve iyi ki gelir; ama çözüm retry'ı kapatmak değil, transaction'ı CreateExecutionStrategy().ExecuteAsync ya da ExecuteInTransactionAsync içine almak.

İkincisi, retry'ın idempotent olmayan bir yazmayı iki kez yapması. Commit sırasında kopan bir connection'dan sonra strategy işi baştan çalıştırır. Store-generated key'lerle (identity) çalışan bir INSERT ikinci kez farklı bir Id ile yazılır ve hata da vermez. İstemci tarafında üretilen bir kimlik (RequestId) ve üzerinde unique index ya da verifySucceeded olmadan retry, veriyi çoğaltabilir. Strategy bloğunun içine e-posta gönderme, ödeme çağrısı gibi tekrarlanmaması gereken işleri de koyma.

Üçüncüsü, production'da EnableSensitiveDataLogging. Müşteri adları, e-posta adresleri, arama terimleri log'a ve oradan log sistemine düşer. IsDevelopment() kontrolünün arkasında tut.

Dördüncüsü, iki katmanda retry. SqlClient'ın ConnectRetryCount'u ile EF Core'un execution strategy'si üst üste binince gördüğümüz gibi biri diğerini gizler ve toplam bekleme süresi beklediğinden uzun olur. Hangisini kullanacağına karar ver ve log'da gör.

Küçük Bir Deneme

★☆☆ API'de EnableRetryOnFailure'ı maxRetryCount: 2 ile çalıştır ve failover denemesini tekrarla. Veritabanını bu kez 20 saniye kapalı tut; istemcinin aldığı hatayı ve log'daki son mesajı not et.

★★☆ POST /orders'ı aynı RequestId ile aynı anda iki kez gönder (iki terminal). Hangisinin unique index'e takıldığını, istemciye ne döndüğünü incele ve endpoint'i bu durumda da var olan siparişi döndürecek hâle getir.

★★★ SlowCommandObserver'ı bir DbCommandInterceptor'a çevir ve iki yaklaşımı karşılaştır: hangisi ReportingContext'in sorgularını da görüyor, hangisi komutu çalışmadan durdurabiliyor?

Böylece "Pratikte EF Core" bloğunu bitirdik: veritabanından model üretmek, LINQ (Language Integrated Query; C# içinden sorgu yazma özelliği) çeviri kataloğu, Fluent API, migration'ların günlük hayatı ve şimdi production'daki dayanıklılık ile gözlem. Seri, bundan sonra EF Core 11 ile gelenlerle devam edecek.