Unity Profiler ile gerçek darboğazı bulmak: 22 ms'ten 8 ms'e

22 ms'lik kare ve yanlış suçlanan shader

Mobil bir tower defense prototipinde 14. dalgadan sonra oyun gözle görülür biçimde takılmaya başlıyordu. Redmi Note 11 üzerinde kare süresi 16,7 ms hedefine karşılık 22,4 ms'e çıkıyor, her iki üç saniyede bir 40 ms'i aşan sıçramalar oluyordu. Takılma her seferinde aynı yerde olmuyordu, bu da tek bir betiği suçlamayı zorlaştırıyordu. Ekipteki ilk tahmin her zamanki gibi shader'lardı: "mobilde bu kadar saydam efekt kaldırmaz".

Cihazı kabloyla bağlayıp Unity Profiler ile 600 karelik bir kayıt aldım. Kaydın hiçbir yerinde shader'a ait kayda değer bir maliyet yoktu. Unity performans optimizasyonu tartışmalarının çoğu tam bu noktada, yani kimsenin ölçmediği bir tahminin üzerine kuruluyor.

Yazının geri kalanı o kaydı hangi sırayla okuduğumu anlatıyor: önce CPU'ya mı GPU'ya mı bağlı olduğumuzu ayırdım, sonra GC Alloc satırlarına indim, en son draw call sayımına baktım. Sıra önemli. Ters gitseydim üç günümü hiçbir şeyi değiştirmeyecek shader sadeleştirmesiyle geçirirdim. Kullanılan sürüm Unity 2022.3 LTS, boru hattı URP, hedef ise Android üzerinde IL2CPP.

CPU mu GPU mu? Önce bunu ayırın

Profiler'da Timeline görünümüne geçip ana iş parçacığı ile render iş parçacığını yan yana koymak, soruların yarısını tek başına kapatıyor. GPU'ya bağlıysanız ana iş parçacığında Gfx.WaitForPresentOnGfxThread ya da Semaphore.WaitForSignal altında geniş bir bekleme bloğu görürsünüz. Bu blok "CPU boşta bekliyor, kart yetişemiyor" demektir.

Bizim kayıtta durum tam tersiydi. PlayerLoop tek başına 22,4 ms'in 19,8 ms'ini yiyordu, GPU tarafı ise 9,1 ms'te işini bitiriyordu. Yani kart karesini erken bitirip bekliyordu; darboğaz baştan sona CPU'daydı ve shader'a dokunmanın frame time üzerinde ölçülebilir bir etkisi olmayacaktı. Aynı kayıtta Gfx.WaitForPresentOnGfxThread satırı 0,4 ms'te duruyordu; yani beklenen bir şey yoktu.

Bu ayrımı yapmadan optimize etmeye başlamak, gördüğüm en yaygın hata. GPU'ya bağlı bir sahnede Update döngülerini kısaltırsanız hiçbir şey değişmez; CPU'ya bağlı bir sahnede tekstür çözünürlüğünü yarıya indirirseniz de öyle. Ayrımı yapmak iki dakika sürüyor, yanlış yönde harcanan hafta geri gelmiyor. Ben bu karar verilmeden tek satır kod değiştirmiyorum.

Bir uyarı: editörde alınan ölçüm bu ayrımı doğru yapmaz. Editör kendi arayüzünü, sahne kamerasını ve profiler penceresinin kendisini aynı ana iş parçacığında çalıştırır. Aynı sahne editörde 31 ms, cihazda 22,4 ms ölçüldü; sadece mutlak değerler değil, bölümlerin birbirine oranı da farklıydı.

GC alloc satırları ne anlatıyor

Hierarchy görünümünde GC Alloc sütununa göre sıraladığımda kare başına ayırma 312 KB çıktı. Bu rakam tek başına takılmaya sebep olmaz, ama biriktikçe çöp toplayıcıyı tetikler ve tetiklendiği karede 1,9 ms'lik bir GC.Collect görürsünüz. Kayıttaki 40 ms'lik sıçramaların tamamı bu satırla aynı karelere denk geliyordu. Toplayıcı yaklaşık 2,6 saniyede bir devreye giriyordu ve bu aralık, kare başına ayırma ile heap büyüme eşiğinin oranından başka bir şey değildi.

Kaynaklar sıkıcı derecede klasikti. HUD'da her karede _scoreText.text = "Skor: " + _score çalışıyordu ve bu tek satır 96 KB üretiyordu; StringBuilder ile yazıp yalnızca değer değiştiğinde atamak bunu sıfıra indirdi. EnemySpawner içindeki _points.Where(p => !p.Blocked).OrderBy(p => p.Distance) zinciri dalga başına değil kare başına çalışıyordu ve LINQ'nun her Where ile OrderBy çağrısı kendi iterator ve karşılaştırıcı nesnesini ayırır. LINQ'yu tamamen yasaklamıyorum; yükleme ve editör kodunda serbest, ama oynanış döngüsünde bu zincir tek başına kare başına 140 KB'a mal oluyordu.

Üçüncü kaynak Physics.OverlapSphere idi; her çağrıda yeni bir Collider[] döndürür. OverlapSphereNonAlloc ile önceden ayrılmış bir diziye yazmak o satırı sıfıra indirdi. Aynı sınıfta Update içinde GetComponent<EnemyPool>() çağrısı da vardı: bu çağrı ayırma yapmaz, ama 240 nesnede kare başına 1,1 ms tutuyordu. Awake içinde bir kez önbelleğe almak yetti.

Ayırmayı okurken sütunun kare başına olduğunu unutmayın. Kare başına 8 KB masum görünür; 60 FPS'te dakikada 28 MB eder ve mobil cihazda çöp toplayıcı bunu er geç durdurma sıçramasıyla toplar. Ben oynanış döngüsünde kare başına 1 KB'ın altını hedefliyorum, çoğu sahnede tam sıfır bile gerçekçi bir hedef. Ölçerken Profiler'ın kendi ayırmalarını da hesaba katın; kaydın ilk birkaç karesi her zaman kirli çıkar.

Deep Profile ne zaman yalan söyler

Deep Profile her metot çağrısının etrafına ölçüm kodu yerleştirir. Kısa ve çok çağrılan metotlarda bu, ölçümün maliyetinin metodun kendisinden büyük olması demek. Bizim sahnede Deep Profile açıkken kare süresi 22,4 ms'ten 61 ms'e çıktı. Bu haliyle ölçtüğünüz şey artık oyununuz değil, ölçüm koduyla şişmiş bir kopyası.

Asıl sorun yavaşlaması değil, sıralamayı bozması. Deep Profile'a göre en pahalı satır Vector3.Distance çağrılarıydı; kapatıp aynı bloğu manuel ProfilerMarker ile ölçtüğümde 0,3 ms çıktı. Ölçüm aracının kendisi profili yeniden yazmıştı.

Bu yüzden kullanım şeklim şu oldu: Deep Profile'ı yalnızca "maliyet hangi alt ağaçta" sorusunu cevaplamak için açıyorum, mutlak süre okumak için asla. Şüpheli bölgeyi bulduktan sonra kapatıp o bloğa elle ProfilerMarker koyuyorum; ek maliyeti ihmal edilebilir ve IL2CPP ile derlenmiş gerçek yapıda da çalışır. Editörde alınmış bir Deep Profile çıktısını hiçbir optimizasyon kararına dayanak yapmıyorum.

Frame Debugger ile draw call sayımı

CPU tarafı düzeldiğinde ana iş parçacığı 11,3 ms'e inmişti, ama render iş parçacığı hâlâ 4,6 ms tutuyordu. Frame Debugger penceresini açtım: 480 draw call. Sahnede 240 düşman vardı, yani düşman başına iki ayrı çizim. Oynanış sırasında duraklatıp kareyi çizim çizim ilerletmek, hangi çağrının neye ait olduğunu görmenin en hızlı yolu.

Frame Debugger her çizimin yanında SRP Batcher'ın zinciri neden kırdığını yazar; okunması gereken asıl bilgi orada. Bizde iki sebep vardı: sağlık çubukları için her düşmana ayrı materyal örneği oluşturulmuştu (renderer.material erişimi materyali klonlar) ve iki farklı atlas kullanılıyordu. Rengi MaterialPropertyBlock ile geçirip her şeyi tek atlasa taşıdıktan sonra sayı 96'ya düştü. Kırılma sebebi genelde "Objects have different materials" ya da "Node has different shader keywords" der ve düzeltmesi koddan çok bir sahne ayarıdır.

Alternatifleri de denedim. Statik batching düşmanlar hareketli olduğu için baştan elendi; GPU instancing ise materyal klonlaması ortadan kalkınca kendiliğinden devreye girdi, ayrıca bir şey yazmak gerekmedi. Mesh birleştirmeyi de düşündüm ama düşmanların ayrı ayrı yok edilmesi gerektiği için o yol kapalıydı. Render iş parçacığı 4,6 ms'ten 1,8 ms'e indi.

Draw call sayısı tek başına kalite ölçüsü değil. Kalan 96 çizimin 40'ı arayüzden geliyordu ve tek bir Canvas her karede yeniden oluşturuluyordu; sabit ve değişen ögeleri iki ayrı Canvas'a ayırmak Canvas.SendWillRenderCanvases maliyetini 2,1 ms'ten 0,4 ms'e indirdi. Frame Debugger bu satırı göstermez, onu Profiler'ın UI bölümünde bulursunuz.

Ölçüm bittiğinde geriye kalan sayılar

Son durum şöyle: ana iş parçacığı 22,4 ms'ten 8,7 ms'e, render iş parçacığı 4,6 ms'ten 1,8 ms'e, kare başına ayırma 312 KB'tan 4 KB'a indi. Beş dakikalık kesintisiz oynanışta tek bir GC.Collect sıçraması görünmedi. Redmi Note 11 üzerinde 60 FPS sabitlendi. Aynı yapıyı Snapdragon 660'lı daha eski bir cihazda denediğimde kare süresi 11,9 ms çıktı; kazanç tek bir telefona özel değildi.

Değişen kod miktarı şaşırtıcı derecede küçüktü: bir StringBuilder, iki önbelleğe alınmış referans, bir NonAlloc çağrısı, bir MaterialPropertyBlock ve bir Canvas ayrımı. Tek bir shader'a dokunulmadı, tek bir model yeniden topolojiden geçmedi. Toplam iş yarım gün sürdü, kaydı okumak ise onun iki saatini aldı.

Uygulanabilir kısmı üç maddede özetlenebilir: her optimizasyon oturumuna gerçek cihazda alınmış bir Profiler kaydıyla başlayın, ilk soruyu "CPU mu GPU mu" olarak sorun, ikinci soruyu GC Alloc sütununa bakarak cevaplayın. Editörde alınan ölçüm sizi yanıltır; tahmin çok daha fazla yanıltır. Sonraki adımı da aynı yöntemle seçin: yeni bir kayıt alın ve o kayıttaki en pahalı satırla devam edin.