Memory Leak Avı: dotnet-gcdump, Heap Snapshot Karşılaştırma ve Yaygın Leak Pattern'leri

Sürüm notu: Bu yazıdaki kodlar .NET 10 (container'da runtime 10.0.15) ile derlenip denenmiştir; dotnet-gcdump, dotnet-dump ve dotnet-counters 10.0.750501, yük için k6 2.4.0, diff script'i için Python 3 kullanılmıştır.

Önce Tahmin Et

Bookstore'da siparişi kargoya veren endpoint 20.000 istek sonra GC (garbage collector; kullanılmayan object'leri temizleyen runtime bileşeni) heap'ini 17,8 MB'tan 348,5 MB'a çıkarmış ve büyümeye devam ediyor. Teşhis için heap'in iki snapshot'ını alacaksın. İki soru: 348 MB'lık heap'ten alınan snapshot dosyası kaç MB olur ve almak process'i ne kadar durdurur? Full dump ile aradaki fark ne? Ve büyüyen object'leri bulduğunda, onları kimin tuttuğunu nereden anlarsın? İlk sorunun cevabı tablodaki sayılarda; ikincisi bu yazının asıl konusu.

gcdump mı, Full Dump mı?

dotnet-gcdump process'in tam bir kopyasını almıyor. EventPipe üzerinden bir gen2 GC tetikliyor ve GC heap'i dolaşırken yayınladığı event'lerden object grafiğini yeniden kuruyor: hangi tipten kaç object var, boyutları ne, kim kime referans veriyor. Object'lerin içeriği (string'lerin değeri, byte array'lerin baytları) dosyaya girmiyor. Aynı process'ten, aynı anda üç dosya aldım:

Leak avında soru "ne birikiyor ve kim tutuyor"; bunun için gcdump yeterli ve production'a çok daha uygun. Dump'ın gerektiği yerler (crash, deadlock, bir string'in içeriğini görmek) ve SOS'un (.NET'in debugger extension'ı) dumpheap/gcroot komutlarıyla aynı soruya cevap vermek, Debugging ve Problem Çözme serisinin "Crash ve Memory Dump Analizi" yazısında anlatıldı; burada o yolu tekrar etmiyoruz.

Vaka: Singleton'a Abone Olan Scoped Handler

// singleton: process boyunca yaşıyor
public sealed class OrderEvents
{
    public event EventHandler<OrderShippedEventArgs>? OrderShipped;

    public void PublishShipped(int orderId) => OrderShipped?.Invoke(this, new OrderShippedEventArgs(orderId));
}

// scoped: her istekte bir instance
public sealed class ShippingEmailHandler
{
    private readonly byte[] _renderBuffer = new byte[16 * 1024];
    private readonly ILogger<ShippingEmailHandler> _logger;

    public ShippingEmailHandler(OrderEvents events, ILogger<ShippingEmailHandler> logger)
    {
        _logger = logger;
        events.OrderShipped += OnOrderShipped;
    }

    public int SentCount { get; private set; }

    private void OnOrderShipped(object? sender, OrderShippedEventArgs e)
    {
        _renderBuffer[0] = (byte)(e.OrderId % 255);
        SentCount++;
        _logger.LogDebug("Shipping email rendered for order {OrderId}", e.OrderId);
    }
}

app.MapPost("/api/orders/{id:int}/ship", (int id, ShippingEmailHandler handler, OrderEvents events) =>
{
    events.PublishShipped(id);
    return Results.Accepted(value: new { id, handler.SentCount });
});

Kod masum görünüyor ve tek istekle denediğinde doğru çalışıyor. Sorun +='de: event'e abone olmak, singleton OrderEvents'in elindeki delegate'e handler'ın bir referansını eklemek demek. İstek bitiyor, DI (dependency injection; bağımlılıkları dışarıdan veren altyapı) scope'u kapanıyor, ama handler singleton'dan erişilebilir olduğu için GC onu toplayamıyor. Üstüne, her yeni yayın bütün eski handler'ları da çağırıyor. 10 sanal kullanıcıyla 5.000'lik dört parti istek gönderdim; p95 ilk iki partide 2,8 ve 2,4 ms, son iki partide 6,0 ms, p99 ise 3,4 ms'den 33 ms'ye çıktı. Bellek sızıntısı burada aynı zamanda bir CPU sızıntısı.

İki Snapshot ve Diff

İlk snapshot'ı 1.000 istekten sonra, ikincisini 20.000 istek daha gönderdikten sonra aldım:

docker exec profseries-api dotnet-gcdump collect -p 1 -o /tmp/snap1.gcdump -v
docker exec profseries-api dotnet-gcdump collect -p 1 -o /tmp/snap2.gcdump -v
docker exec profseries-api dotnet-gcdump report /tmp/snap2.gcdump

Writing gcdump to '/tmp/snap2.gcdump'...
  0.1s: Requesting a .NET Heap Dump
Warning: the target runtime does not support non-lossy (Block) buffering, which requires .NET 11+. Falling back to the default lossy buffering; the gcdump may be incomplete on large heaps.
Found a Gen2 Induced non-background GC Start at 0.305 msec GC Count 601
Found a GC Stop at 18.649 for GC 601, ignoring events from now on.
[  0.4s: Done Dumping .NET heap success=True]
	Finished writing 1924900 bytes.

(-v çıktısını kısalttım.) Toplama 0,4 saniye sürdü; bunun 18,6 ms'si GC'nin bütün thread'leri durdurduğu indüklenmiş gen2. Uyarıya dikkat: .NET 10 runtime'ında event'ler kayıplı tamponla toplanıyor ve çok büyük bir heap'te gcdump eksik kalabiliyor; kayıpsız mod .NET 11 runtime'ı istiyor (serinin son yazısı). report çıktısı:

    348,529,611  GC Heap bytes
         81,838  GC Heap objects

   Object Bytes     Count  Type
        262,168         1  System.Object[] (Bytes > 100K)  [System.Private.CoreLib.dll]
         57,596         1  System.String (Bytes > 10K)  [System.Private.CoreLib.dll]
         49,200         1  System.Int32[] (Bytes > 10K)  [System.Private.CoreLib.dll]
         16,408    21,003  System.Byte[] (Bytes > 10K)  [System.Private.CoreLib.dll]

Bu tabloyu okumanın bir püf noktası var: bu sürümde ilk sütun tipin toplam boyutu değil, o satırdaki object'lerin tek tek boyutu ve sıralama da ona göre. 344 MB'ı tutan 21.003 tane 16 KB'lık byte[], listede dördüncü sırada görünüyor. Gerçek toplamı ve iki snapshot arasındaki farkı görmek için iki raporu çarpıp çıkaran küçük bir script yazdım:

import re
import sys

# dotnet-gcdump report'undaki "object başına byte, adet, tip" satırları
LINE = re.compile(r"^\s*([\d,]+)\s+([\d,]+)\s+(.+?)\s*$")


def load(path):
    totals = {}
    for line in open(path, encoding="utf-8"):
        m = LINE.match(line)
        if not m or "GC Heap" in line:
            continue
        size, count = int(m.group(1).replace(",", "")), int(m.group(2).replace(",", ""))
        name = re.sub(r"\s+\[[^\]]+\]$", "", m.group(3))
        b, c = totals.get(name, (0, 0))
        totals[name] = (b + size * count, c + count)
    return totals


before, after = load(sys.argv[1]), load(sys.argv[2])
rows = []
for name in before.keys() | after.keys():
    (b1, c1), (b2, c2) = before.get(name, (0, 0)), after.get(name, (0, 0))
    rows.append((b2 - b1, c1, c2, name))
print(f"{'Bytes +':>14} {'Count 1':>9} {'Count 2':>9}  Type")
for growth, c1, c2, name in sorted(rows, reverse=True)[:6]:
    print(f"{growth:>14,} {c1:>9,} {c2:>9,}  {name}")

python3 gcdiff.py snap1.txt snap2.txt

       Bytes +   Count 1   Count 2  Type
   328,160,000     1,003    21,003  System.Byte[] (Bytes > 10K)
     1,280,000     1,003    21,003  System.EventHandler<Bookstore.Api.Shipping.OrderShippedEventArgs>
       800,000     1,002    21,002  Bookstore.Api.Shipping.ShippingEmailHandler
       262,168         0         1  System.Object[] (Bytes > 100K)
        59,752       616     1,295  System.Reflection.RuntimeParameterInfo
        25,480     1,014     1,259  System.Reflection.RuntimeMethodInfo

Diff'in en güçlü sinyali sayıların birbirine eşit artması: 20.000 istek, 20.000 yeni handler, 20.000 yeni delegate, 20.000 yeni 16 KB'lık buffer. Byte olarak en büyük satır byte[], ama sorunun sahibi o değil; o yalnızca handler'ın bir field'ı. Leak avında en büyük tipe değil, sayısı istek sayısıyla birlikte artan kendi tipine bak. Bir de LOH'ta (Large Object Heap; büyük object'lerin tutulduğu heap bölgesi) 262 KB'lık tek bir object[] belirmiş: multicast delegate'in invocation list'i. Array dolduğunda iki katı kapasiteyle yeniden oluşturuluyor; 21.002 abone, 32.768 kapasiteli 262 KB'lık bir array'e sığmış ve bu boyutta array artık LOH'ta.

Retention Path: Kim Tutuyor?

Ne biriktiğini bulduk; şimdi hangi referans zincirinin onu canlı tuttuğunu bulmak gerekiyor. Windows'ta .gcdump'ı Visual Studio açıyor: dosyayı açınca managed memory raporu geliyor, ikinci snapshot'ı açıp ilkini karşılaştırma (baseline) olarak seçince tip başına fark sütunları çıkıyor, bir tipi seçince alttaki "Paths to Root" ağacı o object'e kökten giden referans zincirlerini gösteriyor. PerfView'de aynı iş heap stack görünümleri ve diff ile yapılıyor (06). Bu makinede Visual Studio olmadığı için bu adımları Microsoft'un dokümanından aktarıyorum. Linux'ta .gcdump'ı açan bir arayüz yok; zinciri, dotnet-gcdump'ın kendi kullandığı graph sınıflarını çağıran küçük bir console uygulamasıyla çıkardım. Rastgele seçtiğim bir handler için yol:

21002 objects match 'Bookstore.Api.Shipping.ShippingEmailHandler'
  [.NET Roots] (0 B)
  [local vars] (0 B)
  Microsoft.AspNetCore.Builder.WebApplication (48 B)
  Microsoft.Extensions.Hosting.Internal.Host (96 B)
  Microsoft.Extensions.DependencyInjection.ServiceProvider (72 B)
  System.Collections.Concurrent.ConcurrentDictionary<...ServiceIdentifier,...ServiceProvider+ServiceAccessor> (40 B)
  ServiceAccessor (32 B)
  Microsoft.Extensions.DependencyInjection.ServiceLookup.ConstructorCallSite (96 B)
  Bookstore.Api.Shipping.OrderEvents (24 B)
  System.EventHandler<Bookstore.Api.Shipping.OrderShippedEventArgs> (64 B)
  System.Object[] (Bytes > 100K) (262168 B)
  System.EventHandler<Bookstore.Api.Shipping.OrderShippedEventArgs> (64 B)
  Bookstore.Api.Shipping.ShippingEmailHandler (40 B)

(Generic tip adlarının ortasını kısalttım.) Zinciri yukarıdan aşağı okuyunca hikâye çıkıyor: uygulamanın kendisi DI container'ını, container singleton'ları önbelleğe aldığı call site üzerinden OrderEvents'i, OrderEvents event field'ındaki multicast delegate'i, o delegate 21.002 elemanlı invocation list'i, listedeki her delegate de _target field'ıyla bir handler'ı tutuyor. Zincirde kesilmesi gereken halka belli: singleton'dan scoped object'e giden referans.

Düzeltme ve Üçüncü Snapshot

// scoped: her istekte bir instance; request scope'u dispose edilince abonelikten çıkıyor
public sealed class ShippingEmailHandler : IDisposable
{
    private readonly byte[] _renderBuffer = new byte[16 * 1024];
    private readonly OrderEvents _events;
    private readonly ILogger<ShippingEmailHandler> _logger;

    public ShippingEmailHandler(OrderEvents events, ILogger<ShippingEmailHandler> logger)
    {
        _events = events;
        _logger = logger;
        _events.OrderShipped += OnOrderShipped;
    }

    public int SentCount { get; private set; }

    public void Dispose() => _events.OrderShipped -= OnOrderShipped;

    private void OnOrderShipped(object? sender, OrderShippedEventArgs e)
    {
        _renderBuffer[0] = (byte)(e.OrderId % 255);
        SentCount++;
        _logger.LogDebug("Shipping email rendered for order {OrderId}", e.OrderId);
    }
}

DI container'ı scope kapanırken IDisposable olan scoped servisleri dispose ediyor; -= halkayı orada koparıyor. Düzeltilmiş image'ı temiz bir container'da çalıştırıp aynı deneyi tekrarladım ve kanıt olarak iki snapshot daha aldım:

      1,114,462  GC Heap bytes
      1,349,800  GC Heap bytes

       Bytes +   Count 1   Count 2  Type
        60,192       498     1,182  System.Reflection.RuntimeParameterInfo
        26,520       785     1,040  System.Reflection.RuntimeMethodInfo
        22,462     2,178     3,199  System.String

20.000 istekten sonra heap 1,1 MB'tan 1,35 MB'a çıktı ve raporda tek bir ShippingEmailHandler ya da EventHandler<OrderShippedEventArgs> yok. p95 dört partide de 0,66-0,78 ms arasında sabit kaldı. Geriye kalan birkaç on KB'lık artış (reflection tipleri, string'ler) framework'ün ilk çağrılarda dolan iç yapıları olabilir; bunun da büyüyüp büyümediğini bir dördüncü snapshot söyler. Kanıtın kuralı bu: düzeltmeden sonra aynı yükle tekrar ölç ve büyüyen satırın kaybolduğunu göster.

Dispose ile abonelikten çıkmak bu kodun en küçük düzeltmesi, ama tasarım hâlâ kırılgan: biri yeni bir handler yazıp IDisposable'ı unutursa leak geri gelir. Daha sağlam yol, singleton yayıncının scoped handler'ları hiç tutmaması; yayın anında handler'ları o anki scope'tan çözmesi (örneğin IEnumerable<IOrderShippedHandler> olarak) ya da event yerine bir mesaj kuyruğu kullanması.

Yaygın Leak Pattern'leri

Bu vakadaki pattern tek değil. Production'da en sık karşılaştıklarım ve diff'te nasıl göründükleri:

• Event aboneliği: uzun yaşayan bir yayıncıya kısa ömürlü bir abone. Diff'te abone tipiniz ve EventHandler birlikte artar. Mekaniği C# İleri Seviye serisinin "C#'ta Event: EventHandler, Güvenli Tetikleme ve Subscription Leak" yazısında.
• Boyut sınırı olmayan cache: IMemoryCache ya da static bir Dictionary'ye her farklı anahtarla eklemek. Diff'te cache entry tipi ve value'larınız artar. Caching serisinin "IMemoryCache Derinlemesine: SizeLimit, Eviction, Change Token ve GetOrCreate'in Gizli Stampede'i" yazısı SizeLimit'i anlatıyor.
• Captive dependency: singleton'ın constructor'da scoped ya da transient bir servisi alıp tutması. Bu vakaya çok benzeyen bir DI hatası; C# İleri Seviye serisinin "C#'ta Dependency Injection Temelleri: Lifetime'lar, Container ve Captive Dependency" yazısında.
• Dispose edilmeyen timer: çalışan bir Timer runtime'ın timer queue'su tarafından tutuluyor, callback'i de hedef object'i. 02'deki dotnet.timer.count metric'i sürekli artıyorsa buraya bak.
• Sınırsız Channel ya da queue: üretici tüketiciden hızlıysa Channel.CreateUnbounded arada her şeyi biriktirir. CreateBounded ile kapasite ve dolunca ne olacağı (bekle, en eskiyi at) açıkça seçilmeli.
• İstek başına HttpClient: managed heap'te küçük görünür ama soketler ve bağlantılar birikir; Networking ve HTTP serisinin "TCP Nasıl Çalışır: 3-Way Handshake, Congestion Control ve HttpClient Socket Exhaustion" yazısında.

Native Leak İpucu

Her bellek büyümesi managed heap'te değil. dotnet-counters'ta dotnet.process.memory.working_set artarken dotnet.gc.last_collection.heap.size ve memory.committed_size yerinde sayıyorsa büyüyen şey GC'nin dışında: native bir kütüphane, dispose edilmeyen unmanaged kaynaklar (SafeHandle, native buffer'lar), pinned bellek ya da sürekli yeni kod üreten bir şey (03'teki her istekte derlenen Regex gibi). Bu durumda gcdump sana bir şey göstermez, çünkü yalnızca managed heap'i görür. Sıradaki adım full dump ve native bellek araçları: Windows'ta VMMap ve WPR (Windows Performance Recorder; Windows'un performans kayıt aracı) ve WPA (aynı kaydın analiz aracı) ile native heap izleme, Linux'ta dump'ı dotnet-dump analyze ile açıp maddress gibi komutlarla bellek bölgelerine bakmak. Dump tarafının ayrıntısı yine Debugging serisinin 09. yazısında.

Üretimde Dikkat

gcdump ucuz ama bedava değil. Tetiklediği gen2 GC, heap büyüdükçe uzuyor; bu vakada 348 MB'ta 18,6 ms sürdü, birkaç GB'lık bir heap'te yüzlerce milisaniye olabilir ve o sürede bütün istekler bekler. Event tamponu hedef process'te 256 MB'a kadar büyüyebiliyor; memory limit'e yakın çalışan bir container'da gcdump'ın kendisi OOM'a (bellek yetmeyince process'in öldürülmesi) yol açabilir. Mümkünse instance'ı load balancer'dan çekip al, snapshot'ları aynı yük seviyesinde ve aralarında yeterli fark birikecek kadar zaman bırakarak al.

gcdump'ta değer olmasa da tip adları, sayılar ve referans yapısı var; bunlar da sistemin iç yapısı hakkında bilgi verir. Dosyaları dump'larla aynı erişim kuralına koy. Leak'i doğruladıktan sonra en iyi alarm metric'tir: dotnet.gc.last_collection.heap.size'ın gen2 değeri, aynı yük altında saatler boyunca tırmanıyorsa snapshot alma zamanı gelmiştir. 08'de bunun bir collection rule ile otomatik nasıl yapılacağını göreceğiz.

Sık Düşülen Tuzaklar

• Tek snapshot'la leak aramak: tek snapshot neyin büyük olduğunu söyler, neyin büyüdüğünü söylemez.
• İlk snapshot'ı ısınmadan önce almak: cache'ler, connection pool'lar ve lazy alanlar açılışta büyür ve diff'i kirletir.
• dotnet-gcdump report'un ilk sütununu tipin toplamı sanmak; bu yazıyı hazırlarken bir kez beni de yanılttı.
• En büyük byte satırını suçlu ilan etmek: buffer'ı değil, onu tutan handler'ı düzeltmek gerekiyordu.
• Gen2 GC'nin pause'unu hesaba katmadan büyük bir heap'te arka arkaya gcdump almak.
• Düzeltmeyi kod incelemesiyle "kanıtlamak": aynı yükte üçüncü snapshot olmadan leak'in gittiğini bilemezsin.

Küçük Bir Deneme

★☆☆ Lab'ın leak'li sürümüne 5.000'er istekle üç parti gönder, her partiden sonra gcdump al ve diff script'iyle ShippingEmailHandler'ın istek sayısıyla birebir arttığını göster. Windows'taysan aynı iki dosyayı Visual Studio'da açıp baseline karşılaştırmasını dene.

★★☆ OrderEvents'i, handler'ları yayın anında IServiceScopeFactory ile açılan bir scope'tan IEnumerable<IOrderShippedHandler> olarak çözen bir yayıncıyla değiştir. Diff'le leak olmadığını, p95 ile de yayın maliyetinin abone sayısına bağlı olmadığını göster.

★★★ Lab'a Channel.CreateUnbounded<OrderShippedEventArgs>() kullanan ve tüketicisi her mesajda 10 ms bekleyen bir arka plan servisi ekle. Leak'i önce dotnet-counters'ta, sonra iki gcdump'la bul; CreateBounded ve BoundedChannelFullMode.DropOldest ile düzeltip üçüncü snapshot'la kanıtla.

Bu yazıda snapshot'ları elle, komut satırından aldık ve bir tabloyu script'le çarptık. Bir sonraki yazıda aynı işler için Windows'taki en kapsamlı araca geçiyoruz: PerfView ile GC Stats ve JIT (Just-In-Time; kodu çalışma anında makine koduna çeviren derleyici) Stats raporları, grouping/folding ve iki trace'i karşılaştırmak.