systrace adalah alat utama untuk menganalisis kinerja perangkat Android. Namun, itu benar-benar pembungkus di sekitar alat lain. Ini adalah pembungkus sisi host di sekitar atrace , executable sisi perangkat yang mengontrol pelacakan ruang pengguna dan menyiapkan ftrace , dan mekanisme pelacakan utama di kernel Linux. systrace menggunakan atrace untuk mengaktifkan pelacakan, kemudian membaca buffer ftrace dan membungkus semuanya dalam penampil HTML mandiri. (Meskipun kernel yang lebih baru memiliki dukungan untuk Linux Enhanced Berkeley Packet Filter (eBPF), dokumentasi berikut berkaitan dengan kernel 3.18 (tanpa eFPF) karena itulah yang digunakan pada Pixel/Pixel XL.)
systrace dimiliki oleh tim Google Android dan Google Chrome dan merupakan sumber terbuka sebagai bagian dari proyek Catapult . Selain systrace, Catapult menyertakan utilitas berguna lainnya. Misalnya, ftrace memiliki lebih banyak fitur daripada yang dapat langsung diaktifkan oleh systrace atau atrace dan berisi beberapa fungsionalitas lanjutan yang penting untuk men-debug masalah kinerja. (Fitur-fitur ini memerlukan akses root dan seringkali kernel baru.)
Menjalankan systrace
Saat men-debug jitter pada Pixel/Pixel XL, mulailah dengan perintah berikut:
./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000
Saat dikombinasikan dengan tracepoint tambahan yang diperlukan untuk GPU dan aktivitas pipa tampilan, ini memberi Anda kemampuan untuk melacak dari input pengguna ke bingkai yang ditampilkan di layar. Atur ukuran buffer ke sesuatu yang besar untuk menghindari kehilangan event (karena tanpa buffer yang besar beberapa CPU tidak berisi event setelah beberapa titik dalam trace).
Saat melewati systrace, perlu diingat bahwa setiap peristiwa dipicu oleh sesuatu di CPU .
Karena systrace dibangun di atas ftrace dan ftrace berjalan di CPU, sesuatu di CPU harus menulis buffer ftrace yang mencatat perubahan perangkat keras. Ini berarti bahwa jika Anda ingin tahu mengapa pagar tampilan berubah status, Anda dapat melihat apa yang berjalan pada CPU pada titik transisi yang tepat (sesuatu yang berjalan pada CPU memicu perubahan tersebut di log). Konsep ini merupakan dasar dari analisis kinerja menggunakan systrace.
Contoh: Kerangka kerja
Contoh ini menjelaskan systrace untuk pipeline UI normal. Untuk mengikuti contoh, unduh file zip traces (yang juga menyertakan trace lain yang dirujuk di bagian ini), unzip file, dan buka file systrace_tutorial.html di browser Anda. Berhati-hatilah bahwa systrace ini adalah file besar; kecuali jika Anda menggunakan systrace dalam pekerjaan Anda sehari-hari, ini mungkin jejak yang jauh lebih besar dengan lebih banyak informasi daripada yang pernah Anda lihat dalam satu jejak sebelumnya.
Untuk beban kerja berkala yang konsisten seperti TouchLatency, pipeline UI berisi hal berikut:
- EventThread di SurfaceFlinger membangunkan utas UI aplikasi, menandakan bahwa sudah waktunya untuk merender bingkai baru.
- Aplikasi merender bingkai di utas UI, RenderThread, dan hwuiTasks, menggunakan sumber daya CPU dan GPU. Ini adalah sebagian besar kapasitas yang dihabiskan untuk UI.
- Aplikasi mengirimkan bingkai yang dirender ke SurfaceFlinger menggunakan pengikat, lalu SurfaceFlinger tidur.
- EventThread kedua di SurfaceFlinger membangunkan SurfaceFlinger untuk memicu komposisi dan menampilkan output. Jika SurfaceFlinger menentukan bahwa tidak ada pekerjaan yang harus dilakukan, itu akan kembali tidur.
- SurfaceFlinger menangani komposisi menggunakan Hardware Composer (HWC)/Hardware Composer 2 (HWC2) atau GL. Komposisi HWC/HWC2 lebih cepat dan daya lebih rendah tetapi memiliki keterbatasan tergantung pada sistem pada chip (SoC). Ini biasanya memakan waktu ~4-6 md, tetapi dapat tumpang tindih dengan langkah 2 karena aplikasi Android selalu di-buffer tiga kali. (Meskipun aplikasi selalu memiliki buffer tiga kali lipat, mungkin hanya ada satu frame tertunda yang menunggu di SurfaceFlinger, yang membuatnya tampak identik dengan buffering ganda.)
- SurfaceFlinger mengirimkan output akhir untuk ditampilkan dengan driver vendor dan kembali tidur, menunggu bangun EventThread.
Mari kita berjalan melalui frame mulai dari 15409 ms:
Gambar 1 adalah bingkai normal yang dikelilingi oleh bingkai normal, jadi ini adalah titik awal yang baik untuk memahami cara kerja saluran UI. Baris utas UI untuk TouchLatency mencakup warna yang berbeda pada waktu yang berbeda. Batang menunjukkan status berbeda untuk utas:
- Abu- abu . Sedang tidur.
- Biru. Dapat dijalankan (dapat dijalankan, tetapi penjadwal belum memilihnya untuk dijalankan).
- Hijau. Aktif berjalan (penjadwal mengira sedang berjalan).
- Merah. Tidur tanpa gangguan (umumnya tidur di kunci di kernel). Dapat menjadi indikasi beban I/O. Sangat berguna untuk men-debug masalah kinerja.
- Oranye. Tidur tanpa gangguan karena beban I/O.
Untuk melihat alasan tidur yang tidak pernah terputus (tersedia dari sched_blocked_reason sched_blocked_reason), pilih irisan tidur merah yang tidak pernah terputus.
Saat EventThread berjalan, utas UI untuk TouchLatency menjadi dapat dijalankan. Untuk melihat apa yang membangunkannya, klik bagian biru.
Gambar 2 menunjukkan utas TouchLatency UI dibangunkan oleh tid 6843, yang sesuai dengan EventThread. Utas UI membangunkan, merender bingkai, dan mengantrekannya untuk digunakan SurfaceFlinger.
Jika tag binder_driver diaktifkan dalam pelacakan, Anda dapat memilih transaksi binder untuk melihat informasi tentang semua proses yang terlibat dalam transaksi tersebut.
Gambar 4 menunjukkan bahwa, pada 15.423.65 ms Binder:6832_1 di SurfaceFlinger menjadi dapat dijalankan karena tid 9579, yang merupakan RenderThread TouchLatency. Anda juga dapat melihat queueBuffer di kedua sisi transaksi pengikat.
Selama queueBuffer di sisi SurfaceFlinger, jumlah frame tertunda dari TouchLatency berubah dari 1 menjadi 2.
Gambar 5 menunjukkan buffering rangkap tiga, di mana ada dua bingkai yang sudah selesai dan aplikasi akan mulai merender yang ketiga. Ini karena kami telah menjatuhkan beberapa bingkai, jadi aplikasi menyimpan dua bingkai tertunda alih-alih satu untuk mencoba menghindari bingkai yang dijatuhkan lebih lanjut.
Segera setelah itu, utas utama SurfaceFlinger dibangunkan oleh EventThread kedua sehingga dapat menampilkan bingkai tertunda yang lebih lama ke tampilan:
SurfaceFlinger pertama-tama mengunci buffer tertunda yang lebih lama, yang menyebabkan jumlah buffer yang tertunda berkurang dari 2 menjadi 1.
Setelah mengunci buffer, SurfaceFlinger menyiapkan komposisi dan mengirimkan bingkai terakhir ke tampilan. (Beberapa bagian ini diaktifkan sebagai bagian dari mdss mdss, sehingga mungkin tidak disertakan pada SoC Anda.)
Selanjutnya, mdss_fb0 bangun pada CPU 0. mdss_fb0 adalah thread kernel pipeline tampilan untuk mengeluarkan bingkai yang dirender ke tampilan. Kita dapat melihat mdss_fb0 sebagai barisnya sendiri dalam jejak (gulir ke bawah untuk melihat).
mdss_fb0 bangun, berjalan sebentar, memasuki tidur tanpa gangguan, lalu bangun lagi.
Contoh: Bingkai tidak berfungsi
Contoh ini menjelaskan systrace yang digunakan untuk men-debug jitter Pixel/Pixel XL. Untuk mengikuti contoh, unduh file zip trace (termasuk trace lain yang dirujuk di bagian ini), unzip file, dan buka file systrace_tutorial.html di browser Anda.
Saat Anda membuka systrace, Anda akan melihat sesuatu seperti ini:
Saat mencari jank, periksa baris FrameMissed di bawah SurfaceFlinger. FrameMissed adalah peningkatan kualitas hidup yang disediakan oleh HWC2. Saat melihat systrace untuk perangkat lain, baris FrameMissed mungkin tidak ada jika perangkat tidak menggunakan HWC2. Dalam kedua kasus tersebut, FrameMissed berkorelasi dengan SurfaceFlinger yang kehilangan salah satu runtime yang sangat teratur dan jumlah buffering tertunda yang tidak berubah untuk aplikasi ( com.prefabulated.touchlatency ) di vsync.
Gambar 11 menunjukkan bingkai yang terlewat pada 15598,29&nbps;ms. SurfaceFlinger bangun sebentar pada interval vsync dan kembali tidur tanpa melakukan pekerjaan apa pun, yang berarti SurfaceFlinger memutuskan bahwa tidak ada gunanya mencoba mengirim bingkai ke layar lagi. Mengapa?
Untuk memahami bagaimana pipeline rusak untuk frame ini, pertama tinjau contoh kerangka kerja di atas untuk melihat bagaimana pipeline UI normal muncul di systrace. Saat siap, kembali ke bingkai yang terlewat dan kerjakan mundur. Perhatikan bahwa SurfaceFlinger bangun dan segera tidur. Saat melihat jumlah bingkai tertunda dari TouchLatency, ada dua bingkai (petunjuk bagus untuk membantu mencari tahu apa yang terjadi).
Karena kami memiliki bingkai di SurfaceFlinger, ini bukan masalah aplikasi. Selain itu, SurfaceFlinger bangun pada waktu yang tepat, jadi ini bukan masalah SurfaceFlinger. Jika SurfaceFlinger dan aplikasi keduanya terlihat normal, itu mungkin masalah driver.
Karena mdss dan sync tracepoints diaktifkan, kita bisa mendapatkan informasi tentang pagar (dibagi antara driver tampilan dan SurfaceFlinger) yang mengontrol kapan frame dikirimkan ke tampilan. Pagar ini terdaftar di bawah mdss_fb0_retire , yang menunjukkan saat bingkai ditampilkan. Pagar ini disediakan sebagai bagian dari kategori pelacakan sync . Pagar mana yang sesuai dengan kejadian tertentu di SurfaceFlinger bergantung pada SOC dan tumpukan driver Anda, jadi bekerjalah dengan vendor SOC Anda untuk memahami arti kategori pagar dalam jejak Anda.
Gambar 13 menunjukkan bingkai yang ditampilkan selama 33 ms, bukan 16,7 ms seperti yang diharapkan. Setengah jalan melalui irisan itu, bingkai itu seharusnya diganti dengan yang baru tetapi tidak. Lihat bingkai sebelumnya dan cari apa saja.
Gambar 14 menunjukkan 14,482 ms sebuah frame. Segmen dua bingkai yang rusak adalah 33,6 mdtk, yang kira-kira seperti yang kami harapkan untuk dua bingkai (kami merender pada 60 Hz, 16,7 mdtk per bingkai, yang mendekati). Tetapi 14,482 ms sama sekali tidak mendekati 16,7 ms, menunjukkan bahwa ada sesuatu yang sangat salah dengan pipa tampilan.
Selidiki dengan tepat di mana pagar itu berakhir untuk menentukan apa yang mengendalikannya.
Workqueue berisi __vsync_retire_work_handler , yang berjalan saat pagar berubah. Melihat melalui sumber kernel, Anda dapat melihat bahwa itu adalah bagian dari driver tampilan. Tampaknya berada di jalur kritis untuk saluran tampilan, sehingga harus berjalan secepat mungkin. Ini dapat dijalankan untuk 70 kami atau lebih (bukan penundaan penjadwalan yang lama), tetapi ini adalah antrian kerja dan mungkin tidak dijadwalkan secara akurat.
Periksa bingkai sebelumnya untuk menentukan apakah itu berkontribusi; terkadang jitter dapat bertambah seiring waktu dan akhirnya menyebabkan tenggat waktu yang terlewat.
Baris yang dapat dijalankan pada kworker tidak terlihat karena pemirsa mengubahnya menjadi putih saat dipilih, tetapi statistik menceritakan kisahnya: 2,3 ms penundaan penjadwal untuk bagian jalur kritis jalur pipa tampilan buruk . Sebelum melanjutkan, perbaiki penundaan itu dengan memindahkan bagian jalur kritis pipa tampilan ini dari antrian kerja (yang berjalan sebagai SCHED_OTHER CFS) ke SCHED_FIFO SCHED_FIFO khusus. Fungsi ini membutuhkan jaminan waktu yang tidak dapat (dan tidak dimaksudkan untuk) disediakan oleh antrian kerja.
Apakah ini alasan untuk jank? Sulit untuk mengatakan secara meyakinkan. Di luar kasus yang mudah didiagnosis seperti pertikaian kunci kernel yang menyebabkan utas kritis-tampilan tertidur, jejak biasanya tidak menentukan masalahnya. Mungkinkah jitter ini menjadi penyebab frame jatuh? Sangat. Waktu pagar harus 16,7 mdtk, tetapi tidak mendekati itu sama sekali dalam bingkai yang mengarah ke bingkai yang dijatuhkan. Mengingat betapa eratnya sambungan pipa tampilan, ada kemungkinan bahwa jitter di sekitar pengaturan waktu pagar mengakibatkan bingkai jatuh.
Dalam contoh ini, solusinya melibatkan konversi __vsync_retire_work_handler dari workqueue ke kthread khusus. Hal ini menghasilkan peningkatan jitter yang nyata dan mengurangi jank dalam tes bola pantul. Jejak berikutnya menunjukkan waktu pagar yang melayang sangat dekat dengan 16,7 mdtk.