Önü Alınmayan CPU Yükselişi ve Profiling Aracılığıyla Tespit Edilmesi

Bu problem boyunca yaptığımız ciddi code refactor, test ve daha az kaynak ile daha fazla performans elde ettiğimiz çalışmaları makale içerisine dahil etmedim. 8 Mart 2021 günü 2 Instance olacak şekilde Azure Web Application’da çalışan Velocity uygulaması bir anda CPU göstergelerinde ciddi artışlar olduğu ile ilgili hatalar fırlatmaya başladı. PEAKUP’da bu tarz problemlere yaklaşımımız genelde “öncelikle yangını söndür, söndüremiyorsan kontrol altına al ve süreci inceleyip, problem ortadan kaldır” şeklindedir.

Her ne kadar Auto Scaling ile ilgili Azure ayarlarını yapmış olsak da her bir Velocity müşterisi onboarding (tüm içeriklerin girildiği ve kullanıcı eğitimlerinin verildiği) sürecini tamamladıktan sonra kendi içerisindeki kullanıcılarına portal kullanımını duyurdukları zaman sistemi ikinci bir ekranda genel olarak izliyoruz. Anlık gelen kullanıcı sayısını Power BI üzerinden kendi geliştirdiğimiz Analytics Tool’u ile izliyoruz. Bu tarih için planladığımız, olası ansızın gelebilecek bir yük yoktu. Ancak ürünün kullanımı gereği bazı müşteriler portal içerisinden duyuru yaptığında da ansızın bir yük gelebiliyordu. Bu durumda Azure üzerinde otomatik olarak ölçeklendirme için CPU, Memory vb. metrikler üzerinde kurguladığımız alarmlar devreye giriyor ve anında olası bir problemin önüne geçiyorduk.

Bu defa taşıdığımız yük, günlük trafiğimizin ortalamasında olmasına rağmen 12 Instance açıkken bile bir türlü CPU ile ilgili problemi çözemiyorduk. Üzerinden toplantı odaları, yaklaşan toplantılarım vb. bilgileri çektiğimiz ONE uygulaması ve Authenticator uygulaması da herhangi bir spike ile karşı karşıya kalmamasına rağmen Velocity’de sıra dışı bir durum vardı.

Problemi gidermek için kontrol ettiğimiz, denediğimiz bazı adımlar;

  • Bağlı çalışan tüm diğer uygulamaların kaynakları ve veri tabanları yeterli seviyede yükü kaldırıyor mu?
    • Buradaki amacımız Velocity ve diğer tüm ürünlerimizin ortak olarak kullandığı Authenticator ya da bağlı olduğu herhangi bir servisin veritabanı tarafında ya da backend tarafda gönderdiğimiz talepler karşısında herhangi bir bottleneck yaşanıp yaşanmadığını kontrol etmek oldu. Hiçbir problem tespit edilemedi. Aksine fazla kaynak rezerve edildiği tespit edilip bazı kaynaklarda düşüşe gidildi.
  • Öncelikle SQL Server içerisinde Created alanına göre anormal bir veri artışı var mı?
    • Bazı müşteriler ürünü beyaz ve mavi yaka şeklinde ayırıp bu kullanıcılara portallarını belli bir arayla açabiliyorlar. Son gelen kullanıcı sayısında herhangi bir ani artış olup olmadığını inceledik. Ek olarak Velocity’nin free versiyonu tarafından gelebilecek olası bir artış var mı yok mu bu metrikleri kontrol ettik ve sıradışı bir durum tespit edemedik.
  • JSON Formatındaki Verinin Büyüklüğü Bizi Ne Kadar Etkiliyor?
    • Neredeyse iki yıllık haberleşme kayıtlarını, günlük verilerin girildiği, yüzbinlerce telefon numarasının olduğu bazı widgetların içerisindeki veriler işlenirken acaba CPU tarafında buna bağlı bir kilitlenme mi var sorusu aklımıza geldi. Bunun için müşterilerimizden en büyük veriye sahip olan Widgetlardan beş tane seçip bunlara, test ortamında random veriler girmeye başladık ve CPU tarafında hiçbir değişim olmadığını tespit ettik. Sorun yine çözülmedi!
  • Diğer uygulamalara bağlanıp veri çeken Widgetlarımız(Twitter, Toplantı Odaları, İzin Uygulaması, Haberler vb.) widgetlar tarafında mı bir problem var?
    • Bir Intranetin en önemli olan hizmetlerinden olan Toplantı Odaları, Yaklaşan Toplantılarım, Dış Kaynak Haberleri, Bugün Kimler Uzaktan çalışıyor gibi katma değeri en yüksek ama en fazla CPU tüketimi sağlayan widgetları tek tek kontrol ettik. Her birisini teker teker kullanımdan kaldırıp sonrasında CPU ile ilgili durumu monitör ettik. Ciddi bir düşüş gözlemlendi.
  • Problem Spesifik bir serviste mi? Başka servisleri de etkiliyor mu?
    • Bunu görmek için, Velocity’nin kullandığı tüm servislere Apache’nin AB toolu ile hem localde hem de DEV Stage içerisinde Linux bir makine üzerinden 1000 tane 50 Concurrent request göndererek metrikleri takip ettik. Velocity dışında One servisinde bir problem keşfedildi ve giderildi. Ancak sorun Velocity tarafında sürmeye devam etti.

Yüksek CPU kullanacak tüm Widgetları tek tek incelemeye başladık. Önce portaldan kaldırıp sonrasında oluşan yükün artış veya azalış durumuna göre hareket edecektik.

İlgili widgetlarla ilgili tam bir factoring süreci başlatmak üzereyken problemin tekrar yaşandığını ancak bu defa CPU’daki yükselişlerin daha kısa süre içerisinde normale döndüğünü gözlemledik.

Problemin JSON tipindeki verileri işlediğimiz bir aşamadan kaynaklanmadığından emindim. Çünkü CPU tarafındaki kaynakları tüketebilecek diğer tüm işlemler (Image Processing, Video Processing) başka bir servis içerisinde, döviz-hava durumu gibi widgetlar da başka bir servis içerisinden geliyordu. Bu nedenle JSON tarafında en çok işlem yaptığımız methodları inceleyip tekrar testlere başladık.

Velocity içerisindeki Dependency Injection apısı tamamen kullanıcını yaptığı ilk request sonrasında kurgulanmaktadır. Kullanıcının bağlı olduğu Tenant Hybird mi yani İstanbul’daki bir sunucuda mı çalıştığı yoksa Azure üzerinde Cloud’da mı çalıştığı yapılan ilk requestten sonrasında kurgulanmaktadır. Bu aşamada gelen kullanıcının kim olduğunun tanımını yapan endpointi yani tüm isteklerin aktığı OnActionExecutionAsync methodunu incelemeye başladım.

HttpClient kütüphanesi bu gibi arka arkaya yapılan işlemler için önerilmediğinden dolayı IHttpClientFactory tarafından aldığımız CreateClient methoduyla gelen tüm HttpClient objelerini saatlik olarak isimlendirmeye başladık.

İlk başlarda yaşadığımız spike problemi devam etse de CPU’daki %100 ve üzeri oranda takılı kalma problemi yine süre olarak ciddi anlamda düşüş gösterse de problem hala devam etti.

Problemi daha detaylı incelemek için Azure’un Web Application’a özel olarak sunduğu, tüm metrikleri inceleyebileceğiniz bir uygulaması bulunmaktadır. Bu uygulama application Insight olarak geçer. Velocity’de temel özellikleriyle birlikte açık olan bu uygulamanın tüm Profiling ile ilgili özelliklerini açmaya karar verdik.

Kaynakları arttırmaya devam edip, Azure Application Insight ile problemi araştırmaya, metrikleri toplamaya devam ederken şununla karşılaştık. Application Insight sonrasında ortalama olarak çok küçük sayıda diyebileceğimiz isteklerde bile uygulamada CPU %110’ün üzerine çıkmaya başladı. Araştırdığımızda buna başka geliştiricilerin de maruz kaldığını öğrendik. Haliyle Application Insight tarafını tamamen kapattık ve sorun büyük oranda çözülmüş gibi görünmeye başladı.

 

Sonrasındaki bir hafta boyunca herhangi bir problem olmadan devam eden süreç ilerleyen zamanlarda yüksek Memory Exception hatalarıyla tekrar baş göstermeye başladı… Uygulamalarımızı Web Application içerisinde InProcess olacak şekilde doğrudan IIS’e vermekteydik. Application Insight’ın yarattığı yükü kaldırmak ve direkt olarak performansı koruyabilmek için Kestrel üzerinden bir Reverse Proxy yarattık ve artık hataları çok daha derinlemesine görmeye başladık.

 

Uygulama içerisinde Kestrel sayesinde her bir Request ve SQL sorgusunun çıktısını görmeye başladık. Artık Application Insight’ı açıp bunun yanında ek olarak uygulamanın çalıştığı anda yarattığı hataları görebilir hale geldik. Takım arkadaşlarım Fatih Doğan ve Fatih Memiş’in de bu aşamada dahil olduğu süreçte Code Review aşamasına geçtik. Bottleneck (dar boğaz) yaşadığımız yerin daha uygulamaya gelen ilk isteğin işlendi süreçten başlayıp son aşamasına kadar bütün kodu satır satır kontrol etmeye başladık. Bu esnada artık Kestrel’dan hem daha mantıklı hem de daha yardımcı olacak hataları almaya başladık. Zira uygulama bir yerden sonra CPU tarafında herhangi bir problem yaşamasa da memory tarafında ciddi şekilde sorunlar yaşadığımızı ve bunun kurguladığımız Dependecy Injection mimarisinden oluştuğunu keşfettik.

Normal web uygulamalarında tüm Dependency’ler Startup içerisinde tanımlanırken, Velocity’de neredeyse bütün database ile alakalı Dependency’ler ilk requesttin geldiği BaseController içerisinde tanımlanıyor. Bunun sebebi gelen talebi karşılarken minimum seviyede kaynağı ayağa kaldırmak ve bazı davranışsal değişikliklerin request bazında olabilmesini sağlayabilmektir.

Dependency yapısını yönetmek için Startup.cs içerisinde ayağa Singleton olarak kaldırdığımız IServiceCollection Instance’ı problemin ana kaynağı gibi görünmeye başladı.

İhtiyaç olduğu kadar Depdency’i ayağa kaldırdığımız aşamada kullandığımız IServiceCollection sınıfının Scope ile ilgili işlemler bittikten sonra artık kullandığı kaynakları Memory’den atmadığını ve bunun bütün uygulamayı etkilediğini fark ettik. Normalde içerisinden çektiğimiz BuildServiceProvider methodu ile çektiğimiz bir servisi artık IServiceProvider ile yüklemeye karar verdik.

Geçişi sağladıktan sonra metrikleri takip ettiğimizde çok ciddi düşüşün olduğunu fark ettik. Bottleneck’e sebep olan şeyin Startup’da Singleton olarak eklediğimiz IServiceCollection Instance’ının BaseController içerisinde tekrar yeni bir IServiceCollection üzerinden alınması olduğunu keşfettik ve IServiceCollection yerine IServiceProvider ile ihtiyacımız olan Dependency kurgusunu sağladık. Böylece sorun ortadan kalkmış oldu.

Bu süreçte yaşanan sorunlar nedeniyle bizi hoşgörüyle karşılayan tüm Velocity müşterilerine, Fatih Doğan, Fatih Memiş ve tüm Velocity takımına teşekkür ederim.