Java Hafıza Problemleri ve GCViewer

Uzun bir aradan sonra tekrar blog yazmaya vakit bulabildim. Bu uzun aralığa sebep olan da işyerimin tarihinde yaptığı en büyük altyapığı değişikliğinde görev alıyor olmamdı. Geçiş sırasında 24 saatlik nöbetler ile çalıştığımız için gecemiz gündüzümüze karıştı. Çok büyük bır sıkıntı yaşamadan kısa sürede düzelttiğimiz birkaç performans sorunu ile gayet başarılı bir şekilde migration'ı tamamladık.

Büyük miktarda verinin söz konusu olduğu migration sonrası yaşanılan en büyük sorunların başında, Uygulama katmanındaki Uygulama Sunucularının performansı gelir. Aynı anda gelen binlerce istek, milyonlarca kayıdın bulduğu tablolar üzerinden işlem yaparak Uygulama Sunucularındaki JVM'lerin canına okurlar. Gerçek production ortamını yaşamadan bazı performans sorunlarını önceden tespit etmeniz mümkün olmaz. Bunların başında da memory sorunları gelmektedir.

Hepimizin bildiği gibi Java'nın en temel özelliklerinden biri de hafıza'da işi biten (referansı bulunmayan) objelerinin temizliğini GC (Garbace Collector) mekanizması ile otomatik yapmasıdır. Tabii bu güzel özellik Java geliştiricilerinin hafızayı hoyratça ve sorumsuzca kullanmasına neden olmaktadır. Nasıl olsa GC herşeyi temizlemektedir.

Normalde aynı anda 100 isteğe cevap veren uygulama sunucunuz, yeni bir deployment sonrası daha 50 isteğe gelmeden sıkışmaya başlıyor, gelen istekleri kuyruğa atıyor, CPU tavana vuruyorsa, ilk bakmanız gereken yer JVM'in hafızasıdır. Eğer her bir istekte, memory'de çok büyük yer kaplayan objeler işleniyorsa GC'nin çalışması sistemin performansını korkunç derecede düşürecektir.

Genelde Java Uygulamaları, sunucunun toplam hafızası baz alınarak, JVM'in hafızadan kullanacağı maksimumum değeri gösteren -Xmx parametresi ile başlatılır.

JAVA_OPTS="-Xms2048m -Xmx2048m"

Peki yukarıdaki örnekte olduğu gibi JVM, 2GB hafıza ile çalıştırılmış olmasına rağmen çok kötü bir performans gösteriyorsa sorunun hafıza kaynaklı olup olmadığını nasıl anlayacağız? Bunun tespiti için öncelikle JVM'i GC loglaması yaptıran aşağıdaki parametreler ile başlatmamız gerekmektedir.

JAVA_OPTS="-Xms2048m -Xmx2048m -Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps"

-Xloggc: parametresi, her GC çalıştığında verdiğiniz dosyaya loglama yapılmasını -XX:+PrintGCDetails -XX:+PrintGCTimeStamps parametreleri de bu loglamanın detaylı yapılmasını sağlayacaktır. Uygulamamızı tekrardan başlattıktan sonra oluşmaya başlayan log dosyasını (gc.log), http://www.tagtraum.com/gcviewer-download.html adresinden ücretsiz olarak indirebileceğimiz GCViewer ile açmamız yeterlidir. Eğer uygulamamızda bir memory problemi var ise, yük altında iken kısa bir süre sonra aşağıdaki gibi bir resimle karşılaşacağız:

Peki bu resimdeki grafik bize tam olarak ne anlatıyor kısaca anlatmaya çalışayım. Mavi zikzak çizgiler o an JVM'de kullanılan hafızayı, siyah uzun çubuklar ise Full GC'nin çalıştığı zamanları ve pause sürelerini göstermektedir. Ekranın Sağ alt köşesindeki Throughput değeri ise JVM'in GC nedeniyle duraklamadan (pause) geçirdiği sürenin toplam süreye oranını göstermektedir.

Yukarıdaki grafikte JVM'in uygulama açıldıktan yaklaşık 15 dakika sonra memory sıkıntısı çekmeye başladığı, bunun üzerinde hafızadaki kullanılmayan objeleri temizlemek için bol bol GC çalıştırdığı, fakat memory'den büyük yer kaplayan objeler bulunduğu için daha sık GC çalıştırmak zorunda kaldığı açıkça görülmektedir. Throughput değeri %55'lere düşmüş, ortalama pause süresi 3.5sn.'lerde gezinmektedir. Bu şekilde çalışmaya devam eden JVM eninde sonunda "Out Of Memory" hatası alacaktır.

Her ne kadar tercih edilen GC algoritmasına göre pause süreleri değişse de, her GC çalışması sistemde bir performans kaybına yol açar. Aşağıdaki gibi sağlıklı bir GC grafiği için büyük miktarlarda hafıza kullanan objelerden uzak durmak ve de JVM'i güzel "Tune" etmek gerekmektedir.

Görüldüğü gibi bu JVM gayet istikrarlı bir şekilde, kendisine ayrılan hafızanın yarısını kullanarak %98 Throughput değerlerinde çalışmaktadır. Fazla yük yok iken JVM zaten default değerlerinde gayet sağlıklı çalışır. Fakat yük altındayken işler değişir.

Bir başka blogumda yüksek yük altında çeşitli JVM parametrelerini kullanarak Throughput'u nasıl yüksek tutabileceğimizi anlatmaya çalışacağım. Aşağıda da özellikle developer arkadaşlara hitap eden bu konuyla ilgili güzel bir blog mevcut:

No Objects Left Behind

If we believe what the graphic that is telling us that the cost of garbage collection is related to the number of objects left behind, the obvious solution is to not leave objects behind. The most reliable way to release objects as soon as possible is to narrow their scope. We can achieve this by moving statically scoped variables to be instance based. We can move instance based variables to local scoping. We need to ask questions such as: “Can we eliminate this variable altogether? Is there any element in the design that is forcing us to hold onto data for longer than is necessary?” Another important aspect is the JVM’s configuration. Is there anything we can do in that regard to help the garbage collector cope with higher rates of object churn? In a vast majority of cases the answers to these questions are yes, yes, and yes. Beware, this advice gets muddled when you consider objects that have a high cost of acquisition.