Profil rekaman aktivitas JSON dapat sangat berguna untuk memahami dengan cepat waktu yang dihabiskan Bazel selama pemanggilan.
Secara default, untuk semua perintah seperti build dan kueri Bazel akan menulis profil tersebut ke
command.profile.gz. Anda dapat mengonfigurasi apakah profil ditulis dengan flag
--generate_json_trace_profile, dan lokasi penulisannya dengan
flag --profile. Lokasi yang diakhiri dengan .gz
dikompresi dengan GZIP. Gunakan flag
--experimental_announce_profile_path
untuk mencetak jalur ke file ini ke log.
Alat
Anda dapat memuat profil ini ke chrome://tracing atau menganalisis dan
melanjutkan pemrosesannya dengan alat lain.
chrome://tracing
Untuk memvisualisasikan profil, buka chrome://tracing di tab browser Chrome,
klik "Muat", lalu pilih file profil (yang berpotensi dikompresi). Untuk hasil
yang lebih detail, klik kotak di sudut kiri bawah.
Contoh profil:
Gambar 1. Contoh profil.
Anda dapat menggunakan kontrol keyboard berikut untuk menavigasi:
- Tekan
1untuk mode "pilih". Dalam mode ini, Anda dapat memilih kotak tertentu untuk memeriksa detail peristiwa (lihat sudut kiri bawah). Pilih beberapa peristiwa untuk mendapatkan ringkasan dan statistik gabungan. - Tekan
2untuk mode "geser". Lalu, tarik mouse untuk menggerakkan tampilan. Anda juga dapat menggunakana/duntuk berpindah ke kiri/kanan. - Tekan
3untuk mode "zoom". Lalu, tarik mouse untuk memperbesar/memperkecil. Anda juga dapat menggunakanw/suntuk memperbesar/memperkecil. - Tekan
4untuk mode "waktu" yang memungkinkan Anda mengukur jarak antara dua peristiwa. - Tekan
?untuk mempelajari semua kontrol.
bazel analyze-profile
Subperintah Bazel analyze-profile
menggunakan format profil dan mencetak statistik kumulatif untuk
berbagai jenis tugas untuk setiap fase build dan analisis jalur penting.
Misalnya, perintah
$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz
dapat menghasilkan output berupa:
INFO: Profile created on Tue Jun 16 08:59:40 CEST 2020, build ID: 0589419c-738b-4676-a374-18f7bbc7ac23, output base: /home/johndoe/.cache/bazel/_bazel_johndoe/d8eb7a85967b22409442664d380222c0
=== PHASE SUMMARY INFORMATION ===
Total launch phase time 1.070 s 12.95%
Total init phase time 0.299 s 3.62%
Total loading phase time 0.878 s 10.64%
Total analysis phase time 1.319 s 15.98%
Total preparation phase time 0.047 s 0.57%
Total execution phase time 4.629 s 56.05%
Total finish phase time 0.014 s 0.18%
------------------------------------------------
Total run time 8.260 s 100.00%
Critical path (4.245 s):
Time Percentage Description
8.85 ms 0.21% _Ccompiler_Udeps for @local_config_cc// compiler_deps
3.839 s 90.44% action 'Compiling external/com_google_protobuf/src/google/protobuf/compiler/php/php_generator.cc [for host]'
270 ms 6.36% action 'Linking external/com_google_protobuf/protoc [for host]'
0.25 ms 0.01% runfiles for @com_google_protobuf// protoc
126 ms 2.97% action 'ProtoCompile external/com_google_protobuf/python/google/protobuf/compiler/plugin_pb2.py'
0.96 ms 0.02% runfiles for //tools/aquery_differ aquery_differ
Penganalisis Pemanggilan Bazel
Bazel Invocation Analyzer open source menggunakan format profil dan mencetak saran tentang cara meningkatkan performa build. Analisis ini dapat dilakukan menggunakan CLI-nya atau di https://analyzer.engflow.com.
jq
jq seperti sed untuk data JSON. Contoh penggunaan jq untuk mengekstrak semua durasi langkah pembuatan sandbox dalam eksekusi tindakan lokal:
$ zcat $(../bazel-6.0.0rc1-linux-x86_64 info output_base)/command.profile.gz | jq '.traceEvents | .[] | select(.name == "sandbox.createFileSystem") | .dur'
6378
7247
11850
13756
6555
7445
8487
15520
[...]
Informasi profil
Profil berisi beberapa baris. Biasanya sebagian besar baris merepresentasikan thread Bazel dan peristiwa terkaitnya, tetapi beberapa baris khusus juga disertakan.
Baris khusus yang disertakan bergantung pada versi Bazel yang dipanggil saat profil dibuat, dan dapat disesuaikan oleh flag yang berbeda.
Gambar 1 menunjukkan profil yang dibuat menggunakan Bazel v5.3.1 dan menyertakan baris berikut:
action count: Menampilkan jumlah tindakan serentak yang sedang berlangsung. Klik untuk melihat nilai sebenarnya. Harus naik ke nilai--jobsdalam clean build.CPU usage (Bazel): Untuk setiap detik build, menampilkan jumlah CPU yang digunakan oleh Bazel (nilai 1 sama dengan satu core yang sibuk 100%).Critical Path: Menampilkan satu blok untuk setiap tindakan di jalur kritis.Main Thread: Thread utama Bazel. Berguna untuk mendapatkan gambaran tingkat tinggi tentang tindakan Bazel, misalnya "Launch Blaze", "EvaluateTargetPatterns", dan "runAnalysisPhase".Garbage Collector: Menampilkan jeda Pengumpulan Sampah (GC) minor dan besar.
Masalah performa umum
Saat menganalisis profil performa, cari:
- Fase analisis yang lebih lambat dari yang diharapkan (
runAnalysisPhase), terutama di build inkremental. Hal ini bisa menjadi tanda implementasi aturan yang buruk, misalnya penerapan yang meratakan dependensi. Pemuatan paket dapat menjadi lambat karena jumlah target yang berlebihan, makro kompleks, atau glob rekursif. - Setiap tindakan lambat, terutama yang berada di jalur kritis. Anda dapat
membagi tindakan besar menjadi beberapa tindakan yang lebih kecil atau mengurangi
kumpulan dependensi (transitif) untuk mempercepatnya. Periksa juga non-
PROCESS_TIMEtinggi yang tidak biasa (sepertiREMOTE_SETUPatauFETCH). - Bottleneck, yaitu sejumlah kecil thread yang sibuk sementara yang lain tidak ada aktivitas / menunggu hasilnya (lihat sekitar 22 detik dan 29 detik pada Gambar 1). Untuk mengoptimalkan hal ini, kemungkinan besar Anda harus menyentuh implementasi aturan atau Bazel itu sendiri untuk memberikan lebih banyak paralelisme. Hal ini juga bisa terjadi ketika ada jumlah GC yang tidak biasa.
Format file profil
Objek tingkat teratas berisi metadata (otherData) dan data pelacakan yang sebenarnya
(traceEvents). Metadata tersebut berisi informasi tambahan, misalnya ID pemanggilan
dan tanggal pemanggilan Bazel.
Contoh:
{
"otherData": {
"build_id": "101bff9a-7243-4c1a-8503-9dc6ae4c3b05",
"date": "Wed Oct 26 08:22:35 CEST 2022",
"profile_finish_ts": "1677666095162000",
"output_base": "/usr/local/google/_bazel_johndoe/573d4be77eaa72b91a3dfaa497bf8cd0"
},
"traceEvents": [
{"name":"thread_name","ph":"M","pid":1,"tid":0,"args":{"name":"Critical Path"}},
...
{"cat":"build phase marker","name":"Launch Blaze","ph":"X","ts":-1306000,"dur":1306000,"pid":1,"tid":21},
...
{"cat":"package creation","name":"foo","ph":"X","ts":2685358,"dur":784,"pid":1,"tid":246},
...
{"name":"thread_name","ph":"M","pid":1,"tid":11,"args":{"name":"Garbage Collector"}},
{"cat":"gc notification","name":"minor GC","ph":"X","ts":825986,"dur":11000,"pid":1,"tid":11},
...
{"cat":"action processing","name":"Compiling foo/bar.c","ph":"X","ts":54413389,"dur":357594,"pid":1,"args":{"mnemonic":"CppCompile"},"tid":341},
]
}
Stempel waktu (ts) dan durasi (dur) dalam peristiwa rekaman aktivitas diberikan dalam
mikrodetik. Kategori (cat) adalah salah satu nilai enum ProfilerTask.
Perhatikan bahwa beberapa peristiwa akan digabungkan jika sangat singkat dan berdekatan satu sama lain; teruskan --noslim_profile jika Anda ingin mencegah penggabungan peristiwa.
Lihat juga Spesifikasi Format Peristiwa Rekaman Aktivitas Chrome.