systrace adalah alat utama untuk menganalisis kinerja perangkat Android. Namun, ini sebenarnya merupakan pembungkus alat lainnya. Ini adalah pembungkus sisi host di sekitar atrace , sisi perangkat yang dapat dieksekusi yang mengontrol penelusuran ruang pengguna dan menyiapkan ftrace , dan mekanisme penelusuran utama di kernel Linux. systrace menggunakan atrace untuk mengaktifkan penelusuran, lalu 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 diaktifkan secara langsung oleh systrace atau atrace dan berisi beberapa fungsi lanjutan yang sangat 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
Jika digabungkan dengan titik penelusuran tambahan yang diperlukan untuk GPU dan aktivitas saluran tampilan, hal ini memberi Anda kemampuan untuk melacak dari masukan pengguna ke bingkai yang ditampilkan di layar. Tetapkan ukuran buffer ke sesuatu yang besar untuk menghindari kehilangan peristiwa (karena tanpa buffer besar, beberapa CPU tidak memuat peristiwa setelah beberapa titik dalam jejak).
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. Artinya, jika Anda penasaran tentang alasan pagar tampilan berubah status, Anda dapat melihat apa yang sedang berjalan di CPU tepat pada titik transisinya (sesuatu yang berjalan di CPU memicu perubahan tersebut di log). Konsep inilah yang menjadi landasan analisis kinerja menggunakan systrace.
Contoh: Kerangka kerja
Contoh ini menjelaskan systrace untuk pipeline UI normal. Untuk mengikuti contoh ini, unduh file zip jejak (yang juga mencakup jejak lain yang dirujuk di bagian ini), unzip file tersebut, dan buka file systrace_tutorial.html di browser Anda. Berhati-hatilah karena systrace ini adalah file besar; kecuali Anda menggunakan systrace dalam pekerjaan Anda sehari-hari, ini mungkin merupakan jejak yang jauh lebih besar dengan lebih banyak informasi daripada yang pernah Anda lihat dalam satu jejak sebelumnya.
Untuk beban kerja yang konsisten dan berkala seperti TouchLatency, alur UI berisi hal berikut:
- EventThread di SurfaceFlinger membangunkan thread UI aplikasi, menandakan bahwa sudah waktunya untuk merender frame baru.
- Aplikasi ini merender bingkai di thread UI, RenderThread, dan hwuiTasks, menggunakan sumber daya CPU dan GPU. Ini adalah sebagian besar kapasitas yang dikeluarkan untuk UI.
- Aplikasi mengirimkan bingkai yang dirender ke SurfaceFlinger menggunakan pengikat, lalu SurfaceFlinger masuk ke mode tidur.
- EventThread kedua di SurfaceFlinger membangunkan SurfaceFlinger untuk memicu komposisi dan menampilkan output. Jika SurfaceFlinger menentukan bahwa tidak ada pekerjaan yang harus diselesaikan, SurfaceFlinger akan kembali ke mode 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 sebuah chip (SoC). Proses ini biasanya membutuhkan waktu ~4-6 ms, namun bisa tumpang tindih dengan langkah 2 karena aplikasi Android selalu memiliki buffering tiga kali lipat. (Meskipun aplikasi selalu memiliki buffering 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 kebangkitan EventThread.
Mari kita telusuri frame yang dimulai pada 15409 ms:
Gambar 1 adalah bingkai normal yang dikelilingi oleh bingkai normal, jadi ini merupakan titik awal yang baik untuk memahami cara kerja pipeline UI. Baris thread UI untuk TouchLatency menyertakan warna berbeda pada waktu berbeda. Batang menunjukkan status berbeda untuk thread:
- Abu-abu . Sedang tidur.
- Biru. Runnable (dapat dijalankan, namun penjadwal belum memilihnya untuk dijalankan).
- Hijau. Berjalan secara aktif (penjadwal menganggapnya sedang berjalan).
- Merah. Tidur tanpa gangguan (umumnya tidur dengan 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 tak terputus (tersedia dari titik jejak sched_blocked_reason ), pilih potongan tidur tak terputus berwarna merah.
Saat EventThread berjalan, thread UI untuk TouchLatency menjadi dapat dijalankan. Untuk melihat apa yang membangunkannya, klik bagian biru.
Gambar 2 menunjukkan thread UI TouchLatency dibangunkan oleh tid 6843, yang sesuai dengan EventThread. Utas UI membangunkan, merender bingkai, dan memasukkannya ke dalam antrean untuk digunakan oleh SurfaceFlinger.
Jika tag binder_driver diaktifkan di pelacakan, Anda dapat memilih transaksi pengikat 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 yang tertunda dari TouchLatency berubah dari 1 menjadi 2.
Gambar 5 menunjukkan buffering tiga kali lipat, yaitu ada dua frame yang telah selesai dan aplikasi akan mulai merender frame ketiga. Hal ini karena kita telah menghapus beberapa frame, sehingga aplikasi menyimpan dua frame yang tertunda, bukan satu frame, untuk mencoba menghindari frame yang hilang lebih lanjut.
Segera setelah itu, thread utama SurfaceFlinger dibangunkan oleh EventThread kedua sehingga dapat menampilkan frame lama yang tertunda ke tampilan:
SurfaceFlinger pertama-tama mengunci buffer lama yang tertunda, yang menyebabkan jumlah buffer tertunda berkurang dari 2 menjadi 1.
Setelah mengunci buffer, SurfaceFlinger menyiapkan komposisi dan mengirimkan bingkai akhir ke tampilan. (Beberapa bagian ini diaktifkan sebagai bagian dari titik jejak mdss , sehingga mungkin tidak disertakan di SoC Anda.)
Selanjutnya, mdss_fb0 aktif 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 di jejak (gulir ke bawah untuk melihatnya).
mdss_fb0 bangun, berlari sebentar, memasuki tidur tanpa gangguan, lalu bangun lagi.
Contoh: Rangka yang tidak berfungsi
Contoh ini menjelaskan systrace yang digunakan untuk men-debug jitter Pixel/Pixel XL. Untuk mengikuti contoh ini, unduh file zip jejak (yang mencakup jejak lain yang dirujuk di bagian ini), unzip file tersebut, 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 reguler dan jumlah buffer tertunda yang tidak berubah untuk aplikasi ( com.prefabulated.touchlatency ) pada vsync.
Gambar 11 menunjukkan frame yang terlewat pada 15598,29&nbps;ms. SurfaceFlinger terbangun 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 alur rusak untuk frame ini, pertama-tama tinjau contoh kerangka kerja di atas untuk melihat bagaimana alur UI normal muncul di systrace. Jika sudah siap, kembali ke bingkai yang terlewat dan kerjakan mundur. Perhatikan bahwa SurfaceFlinger bangun dan segera tertidur. Saat melihat jumlah frame yang tertunda dari TouchLatency, ada dua frame (petunjuk bagus untuk membantu mengetahui apa yang terjadi).
Karena kami memiliki bingkai di SurfaceFlinger, ini bukan masalah aplikasi. Selain itu, SurfaceFlinger aktif pada waktu yang tepat, jadi ini bukan masalah SurfaceFlinger. Jika SurfaceFlinger dan aplikasinya terlihat normal, mungkin masalahnya adalah driver.
Karena titik pelacakan mdss dan sync diaktifkan, kita dapat memperoleh informasi tentang pagar (yang digunakan bersama antara driver tampilan dan SurfaceFlinger) yang mengontrol kapan bingkai dikirimkan ke layar. Pagar ini terdaftar di bawah mdss_fb0_retire , yang menunjukkan kapan sebuah bingkai ada di layar. Pagar ini disediakan sebagai bagian dari kategori pelacakan sync . Pagar mana yang sesuai dengan peristiwa tertentu di SurfaceFlinger bergantung pada SOC dan tumpukan driver Anda, jadi bekerjalah dengan vendor SOC Anda untuk memahami arti kategori pagar di jejak Anda.
Gambar 13 menunjukkan bingkai yang ditampilkan selama 33 ms, bukan 16,7 ms seperti yang diharapkan. Di tengah potongan itu, bingkai itu seharusnya diganti dengan yang baru tetapi ternyata tidak. Lihat bingkai sebelumnya dan cari apa saja.
Gambar 14 menunjukkan frame 14,482 ms. Segmen dua frame yang rusak adalah 33,6 ms, kira-kira sama dengan apa yang kami harapkan untuk dua frame (kami merender pada 60 Hz, 16,7 ms per frame, yang mana hampir sama). Namun 14,482 ms sama sekali tidak mendekati 16,7 ms, menunjukkan ada sesuatu yang salah dengan pipa tampilan.
Selidiki dengan tepat di mana ujung pagar itu untuk menentukan apa yang mengendalikannya.
Antrean kerja 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 jalur ini berada di jalur kritis untuk alur tampilan, sehingga harus dijalankan secepat mungkin. Ini dapat dijalankan untuk 70 orang atau lebih (bukan penundaan penjadwalan yang lama), tetapi ini merupakan antrian kerja dan mungkin tidak dijadwalkan secara akurat.
Periksa frame sebelumnya untuk menentukan apakah itu berkontribusi; terkadang kegelisahan dapat bertambah seiring berjalannya waktu dan akhirnya menyebabkan tenggat waktu terlewati.
Garis yang dapat dijalankan di kworker tidak terlihat karena pemirsa mengubahnya menjadi putih ketika dipilih, tetapi statistik menceritakan kisahnya: penundaan penjadwal 2,3 ms untuk bagian jalur kritis pipa tampilan adalah buruk . Sebelum melanjutkan, perbaiki penundaan tersebut dengan memindahkan bagian jalur kritis alur tampilan ini dari antrean kerja (yang berjalan sebagai thread CFS SCHED_OTHER ) ke kthread SCHED_FIFO khusus. Fungsi ini memerlukan jaminan waktu yang tidak dapat (dan tidak dimaksudkan) disediakan oleh antrean kerja.
Apakah ini alasan janknya? Sulit untuk mengatakannya secara meyakinkan. Di luar kasus yang mudah didiagnosis seperti perselisihan kunci kernel yang menyebabkan thread kritis tampilan tertidur, jejak biasanya tidak menentukan masalahnya. Mungkinkah kegugupan ini menjadi penyebab jatuhnya frame? Sangat. Waktu pagar seharusnya 16,7 ms, namun tidak mendekati waktu tersebut sama sekali pada frame yang mengarah ke frame yang dijatuhkan. Mengingat betapa eratnya pasangan pipa tampilan, mungkin saja jitter di sekitar pengaturan waktu pagar mengakibatkan bingkai terjatuh.
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 pengujian bola memantul. Jejak selanjutnya menunjukkan waktu pagar yang mendekati 16,7 ms.