Systrace'i Anlamak

Systrace, Android cihaz performansını analiz etmek için birincil araçtır. Ancak, aslında diğer araçların etrafını saran bir örtüdür. Bu, atrace etrafındaki ana bilgisayar tarafındaki sarmalayıcı, kullanıcı alanı izlemeyi kontrol eden ve ftrace'i ayarlayan aygıt tarafındaki yürütülebilir dosya ve Linux çekirdeğindeki birincil izleme mekanizmasıdır. systrace, izlemeyi etkinleştirmek için atrace'i kullanır, ardından ftrace arabelleğini okur ve hepsini bağımsız bir HTML görüntüleyiciye sarar. (Daha yeni çekirdekler Linux Geliştirilmiş Berkeley Paket Filtresi (eBPF) desteğine sahip olsa da, aşağıdaki belgeler Pixel/Pixel XL'de kullanılan 3.18 çekirdeğe (eFPF yok) ilişkindir.)

systrace, Google Android ve Google Chrome ekiplerine aittir ve Catapult projesinin bir parçası olarak açık kaynaktır. Catapult, Systrace'e ek olarak başka yararlı araçlar da içerir. Örneğin, ftrace, systrace veya atrace tarafından doğrudan etkinleştirilebilecek olandan daha fazla özelliğe sahiptir ve performans sorunlarının hatalarını ayıklamak için kritik olan bazı gelişmiş işlevler içerir. (Bu özellikler root erişimi ve genellikle yeni bir çekirdek gerektirir.)

Systrace'i çalıştırma

Pixel/Pixel XL'de titreşimde hata ayıklarken aşağıdaki komutla başlayın:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

GPU ve ekran işlem hattı etkinliği için gereken ek izleme noktalarıyla birleştirildiğinde bu, kullanıcı girişinden ekranda görüntülenen kareye kadar izleme olanağı sağlar. Olayların kaybolmasını önlemek için arabellek boyutunu büyük bir değere ayarlayın (çünkü büyük bir arabellek olmadan bazı CPU'lar izlemedeki bir noktadan sonra hiçbir olay içermez).

Systrace'ten geçerken her olayın CPU'daki bir şey tarafından tetiklendiğini unutmayın.

Systrace ftrace'in üzerine inşa edildiğinden ve ftrace CPU üzerinde çalıştığından, CPU üzerindeki bir şeyin donanım değişikliklerini günlüğe kaydeden ftrace arabelleğini yazması gerekir. Bu, bir ekran çitinin neden durum değiştirdiğini merak ediyorsanız, geçişin tam noktasında CPU üzerinde neyin çalıştığını görebileceğiniz anlamına gelir (CPU üzerinde çalışan bir şey, günlükteki bu değişikliği tetikledi). Bu kavram, systrace kullanarak performansı analiz etmenin temelidir.

Örnek: Çalışma çerçevesi

Bu örnekte normal bir UI ardışık düzenine yönelik bir sistem açıklanmaktadır. Örneği takip etmek için, izlemelerin zip dosyasını indirin (bu bölümde adı geçen diğer izlemeleri de içerir), dosyayı açın ve systrace_tutorial.html dosyasını tarayıcınızda açın. Bu sistemin büyük bir dosya olduğu konusunda uyarılmalıdır; Günlük işlerinizde systrace kullanmıyorsanız, bu muhtemelen daha önce tek bir izde gördüğünüzden çok daha fazla bilgi içeren çok daha büyük bir izdir.

TouchLatency gibi tutarlı, periyodik bir iş yükü için kullanıcı arayüzü ardışık düzeni aşağıdakileri içerir:

  1. SurfaceFlinger'daki EventThread, uygulama kullanıcı arayüzü iş parçacığını uyandırarak yeni bir çerçeve oluşturma zamanının geldiğini bildirir.
  2. Uygulama, CPU ve GPU kaynaklarını kullanarak UI iş parçacığı, RenderThread ve hwuiTasks'ta bir çerçeve oluşturur. Bu, kullanıcı arayüzü için harcanan kapasitenin büyük kısmıdır.
  3. Uygulama, oluşturulan çerçeveyi bir ciltleyici kullanarak SurfaceFlinger'a gönderir ve ardından SurfaceFlinger uyku moduna geçer.
  4. SurfaceFlinger'daki ikinci bir EventThread, kompozisyonu ve görüntü çıktısını tetiklemek için SurfaceFlinger'ı uyandırır. SurfaceFlinger yapılacak bir iş olmadığına karar verirse tekrar uyku moduna geçer.
  5. SurfaceFlinger, kompozisyonu Hardware Composer (HWC)/Hardware Composer 2 (HWC2) veya GL kullanarak yönetir. HWC/HWC2 bileşimi daha hızlı ve daha düşük güçtür ancak çip üzerindeki sisteme (SoC) bağlı olarak sınırlamaları vardır. Bu genellikle ~4-6 ms sürer, ancak Android uygulamaları her zaman üçlü ara belleğe alındığından 2. adımla çakışabilir. (Uygulamalar her zaman üçlü arabelleğe alınırken, SurfaceFlinger'da bekleyen yalnızca bir çerçeve olabilir, bu da onun çift ara belleğe almayla aynı görünmesini sağlar.)
  6. SurfaceFlinger, son çıktıyı satıcı sürücüsüyle görüntülenmek üzere gönderir ve EventThread'in uyanmasını bekleyerek tekrar uyku moduna geçer.

15409 ms'den başlayan çerçeveye göz atalım:

EventThread'in çalıştığı normal kullanıcı arayüzü ardışık düzeni
Şekil 1. Normal UI ardışık düzeni, EventThread çalışıyor

Şekil 1, normal çerçevelerle çevrelenmiş normal bir çerçevedir; dolayısıyla UI işlem hattının nasıl çalıştığını anlamak için iyi bir başlangıç ​​noktasıdır. TouchLatency için kullanıcı arayüzü iş parçacığı satırı farklı zamanlarda farklı renkler içerir. Çubuklar iş parçacığının farklı durumlarını belirtir:

  • Gri . Uyuyor.
  • Mavi. Çalıştırılabilir (çalışabilir, ancak zamanlayıcı henüz onu çalıştırmayı seçmedi).
  • Yeşil. Aktif olarak çalışıyor (zamanlayıcı çalıştığını düşünüyor).
  • Kırmızı. Kesintisiz uyku (genellikle çekirdekteki bir kilit üzerinde uyumak). G/Ç yükünün göstergesi olabilir. Performans sorunlarını ayıklamak için son derece faydalıdır.
  • Turuncu. G/Ç yükü nedeniyle kesintisiz uyku.

Kesintisiz uyku nedenini görüntülemek için ( sched_blocked_reason izleme noktasından edinilebilir), kırmızı kesintisiz uyku dilimini seçin.

EventThread çalışırken TouchLatency için kullanıcı arayüzü iş parçacığı çalıştırılabilir hale gelir. Onu neyin uyandırdığını görmek için mavi bölüme tıklayın.

TouchLatency için kullanıcı arayüzü iş parçacığı
Şekil 2. TouchLatency için kullanıcı arayüzü iş parçacığı

Şekil 2, TouchLatency UI iş parçacığının, EventThread'e karşılık gelen tid 6843 tarafından uyandırıldığını göstermektedir. UI iş parçacığı uyanır, bir çerçeve oluşturur ve onu SurfaceFlinger'ın kullanması için sıraya alır.

UI iş parçacığı uyanır, bir çerçeve oluşturur ve onu SurfaceFlinger'ın kullanması için sıraya koyar
Şekil 3. UI iş parçacığı uyanır, bir çerçeve oluşturur ve onu SurfaceFlinger'ın kullanması için sıraya koyar

Bir izlemede binder_driver etiketi etkinleştirilmişse, bir binder işlemini seçerek bu işlemde yer alan tüm işlemlere ilişkin bilgileri görüntüleyebilirsiniz.

Şekil 4. Bağlayıcı işlemi

Şekil 4, SurfaceFlinger'daki Binder:6832_1'in 15.423,65 ms'de TouchLatency'nin RenderThread'i olan tid 9579 nedeniyle çalıştırılabilir hale geldiğini göstermektedir. Ayrıca ciltleme işleminin her iki tarafında da kuyrukBuffer'ı görebilirsiniz.

SurfaceFlinger tarafındaki QueueBuffer sırasında TouchLatency'den bekleyen karelerin sayısı 1'den 2'ye çıkar.

Bekleyen çerçeveler 1'den 2'ye gider
Şekil 5. Bekleyen çerçevelerin sayısı 1'den 2'ye gidiyor

Şekil 5, iki tamamlanmış çerçevenin olduğu ve uygulamanın üçüncüyü oluşturmaya başlamak üzere olduğu üçlü ara belleğe almayı göstermektedir. Bunun nedeni, bazı kareleri zaten düşürmüş olmamızdır; bu nedenle, daha fazla kare atılmasını önlemek için uygulama bir yerine iki bekleyen kare tutar.

Kısa bir süre sonra SurfaceFlinger'ın ana iş parçacığı ikinci bir EventThread tarafından uyandırılır, böylece bekleyen eski çerçevenin çıktısını ekrana verebilir:

SurfaceFlinger'ın ana iş parçacığı ikinci bir EventThread tarafından uyandırıldı
Şekil 6. SurfaceFlinger'ın ana iş parçacığı ikinci bir EventThread tarafından uyandırılıyor

SurfaceFlinger ilk önce eski bekleyen arabelleği mandallar, bu da bekleyen arabellek sayısının 2'den 1'e düşmesine neden olur.

SurfaceFlinger ilk önce daha eski bekleyen ara belleğe kilitlenir
Şekil 7. SurfaceFlinger ilk olarak eski bekleyen ara belleğe kilitlenir

Arabelleği kilitledikten sonra SurfaceFlinger kompozisyonu ayarlar ve son kareyi ekrana gönderir. (Bu bölümlerden bazıları mdss izleme noktasının bir parçası olarak etkinleştirilmiştir, dolayısıyla SoC'nize dahil edilmeyebilirler.)

SurfaceFlinger kompozisyonu ayarlar ve son kareyi gönderir
Şekil 8. SurfaceFlinger kompozisyonu hazırlıyor ve son kareyi gönderiyor

Daha sonra, mdss_fb0 CPU 0'da uyanır. mdss_fb0 ekrana işlenmiş bir çerçevenin çıktısını almak için ekran hattının çekirdek iş parçacığıdır. İzlemede mdss_fb0 kendi satırı olarak görebiliriz (görüntülemek için aşağı kaydırın).

mdss_fb0 CPU 0'da uyanır
Şekil 9. mdss_fb0 CPU 0'da uyanıyor

mdss_fb0 uyanır, kısa süre çalışır, kesintisiz uykuya girer ve tekrar uyanır.

Örnek: Çalışmayan çerçeve

Bu örnekte Pixel/Pixel XL titreşiminde hata ayıklamak için kullanılan bir sistem açıklanmaktadır. Örneği takip etmek için, izlemelerin zip dosyasını indirin (bu bölümde bahsedilen diğer izlemeleri de içerir), dosyayı açın ve systrace_tutorial.html dosyasını tarayıcınızda açın.

Systrace'i açtığınızda şöyle bir şey göreceksiniz:

Çoğu seçeneğin etkin olduğu Pixel XL'de TouchLatency çalışıyor
Şekil 10. Pixel XL'de çalışan TouchLatency (mdss ve kgsl izleme noktaları dahil çoğu seçenek etkindir)

Jank ararken SurfaceFlinger'ın altındaki FrameMissed satırını kontrol edin. FrameMissed, HWC2 tarafından sağlanan bir yaşam kalitesi iyileştirmesidir. Diğer cihazlar için systrace'i görüntülerken, cihaz HWC2 kullanmıyorsa FrameMissed satırı mevcut olmayabilir. Her iki durumda da, FrameMissed, SurfaceFlinger'ın son derece düzenli çalışma sürelerinden birini ve vsync'de uygulama için değişmeyen bekleyen arabellek sayısını ( com.prefabulated.touchlatency ) kaçırmasıyla ilişkilidir.

SurfaceFlinger ile FrameMissed korelasyonu
Şekil 11. SurfaceFlinger ile FrameMissed korelasyonu

Şekil 11, 15598,29 ms'de kaçırılan bir çerçeveyi göstermektedir. SurfaceFlinger, vsync aralığında kısa bir süreliğine uyandı ve herhangi bir iş yapmadan tekrar uyku moduna geçti; bu, SurfaceFlinger'ın ekrana tekrar çerçeve göndermeye çalışmanın değmeyeceğine karar verdiği anlamına geliyor. Neden?

İşlem hattının bu çerçeveye göre nasıl bozulduğunu anlamak için öncelikle yukarıdaki çalışma çerçevesi örneğini inceleyerek normal bir UI işlem hattının systrace'de nasıl göründüğünü görün. Hazır olduğunuzda kaçırılan kareye dönün ve geriye doğru çalışın. SurfaceFlinger'ın uyandığına ve hemen uykuya geçtiğine dikkat edin. TouchLatency'de bekleyen karelerin sayısını görüntülerken iki kare vardır (neler olup bittiğini anlamanıza yardımcı olacak iyi bir ipucu).

SurfaceFlinger uyanır ve hemen uykuya dalar
Şekil 12. SurfaceFlinger uyanır ve hemen uykuya dalar

SurfaceFlinger'da çerçevelerimiz olduğundan bu bir uygulama sorunu değil. Ayrıca SurfaceFlinger doğru zamanda uyanıyor, dolayısıyla bu bir SurfaceFlinger sorunu değil. SurfaceFlinger ve uygulamanın her ikisi de normal görünüyorsa, bu muhtemelen bir sürücü sorunudur.

mdss ve sync izleme noktaları etkinleştirildiği için, çerçevelerin ekrana ne zaman gönderileceğini kontrol eden çitler (ekran sürücüsü ile SurfaceFlinger arasında paylaşılan) hakkında bilgi alabiliriz. Bu çitler, ekranda bir çerçevenin bulunduğunu belirten mdss_fb0_retire altında listelenir. Bu çitler sync izleme kategorisinin bir parçası olarak sağlanır. SurfaceFlinger'da belirli olaylara hangi çitlerin karşılık geldiği SOC'nize ve sürücü yığınınıza bağlıdır; bu nedenle izlerinizdeki çit kategorilerinin anlamını anlamak için SOC satıcınızla birlikte çalışın.

mdss_fb0_çitleri emekliye ayırma
Şekil 13. mdss_fb0_retire çitleri

Şekil 13, beklendiği gibi 16,7 ms değil, 33 ms boyunca görüntülenen bir kareyi göstermektedir. Bu dilimin yarısında, o çerçevenin yenisiyle değiştirilmesi gerekiyordu ama yapılmadı. Önceki kareyi görüntüleyin ve herhangi bir şey arayın.

Bozuk çerçeveden önceki çerçeve
Şekil 14. Bozulan çerçeveden önceki çerçeve

Şekil 14'te 14,482 ms'lik bir çerçeve gösterilmektedir. Kırık iki kare segmenti 33,6 ms idi; bu da kabaca iki kare için beklediğimiz değerdi (60 Hz'de, kare başına 16,7 ms'de görüntü oluşturuyoruz, bu da yakın bir değer). Ancak 14,482 ms, 16,7 ms'ye hiç yakın değil, bu da ekran borusunda bir sorun olduğunu gösteriyor.

Onu neyin kontrol ettiğini belirlemek için çitin tam olarak nerede bittiğini araştırın.

Çit ucunu araştırın
Şekil 15. Çit ucunu inceleyin

Bir çalışma kuyruğu, çit değiştiğinde çalışan __vsync_retire_work_handler içerir. Çekirdek kaynağına baktığınızda bunun ekran sürücüsünün bir parçası olduğunu görebilirsiniz. Görüntüleme hattı için kritik yolda gibi görünüyor, bu nedenle mümkün olduğu kadar hızlı çalışması gerekiyor. Yaklaşık 70 saat kadar çalıştırılabilir (uzun bir planlama gecikmesi değil), ancak bu bir çalışma kuyruğu ve doğru şekilde programlanamayabilir.

Bunun katkıda bulunup bulunmadığını belirlemek için önceki çerçeveyi kontrol edin; Bazen gerginlik zamanla artabilir ve sonunda son teslim tarihinin kaçırılmasına neden olabilir.

Önceki çerçeve
Şekil 16. Önceki kare

Kworker'daki çalıştırılabilir çizgi, görüntüleyici seçildiğinde onu beyaza çevirdiği için görünmüyor, ancak istatistikler hikayeyi anlatıyor: Görüntüleme ardışık düzeninin kritik yolunun bir kısmı için 2,3 ms'lik zamanlayıcı gecikmesi kötü . Devam etmeden önce, görüntüleme işlem hattı kritik yolunun bu bölümünü bir çalışma kuyruğundan ( SCHED_OTHER CFS iş parçacığı olarak çalışan) özel bir SCHED_FIFO iş parçacığına taşıyarak gecikmeyi düzeltin. Bu işlevin, çalışma kuyruklarının sağlayamayacağı (ve sağlaması amaçlanmayan) zamanlama garantilerine ihtiyacı vardır.

Jankın nedeni bu mu? Kesin olarak söylemek zor. Ekran açısından kritik iş parçacıklarının uyku moduna geçmesine neden olan çekirdek kilidi çekişmesi gibi teşhis edilmesi kolay durumlar dışında, izler genellikle sorunu belirtmez. Bu titreme karenin düşmesinin nedeni olabilir mi? Kesinlikle. Çitleme süreleri 16,7 ms olmalıdır, ancak bırakılan kareye giden karelerde buna hiç de yakın değiller. Ekran hattının ne kadar sıkı bir şekilde bağlandığı göz önüne alındığında, çit zamanlamalarının etrafındaki titreşimin çerçevenin düşmesine yol açması mümkündür.

Bu örnekte çözüm, __vsync_retire_work_handler bir çalışma kuyruğundan özel bir kthread'e dönüştürülmesini içeriyordu. Bu, seken top testinde gözle görülür titreşim iyileşmeleri ve sarsıntının azalmasıyla sonuçlandı. Sonraki izler çit zamanlamalarının 16,7 ms'ye çok yakın olduğunu gösteriyor.