Profil pelacakan JSON bisa sangat berguna untuk memahami dengan cepat biaya yang dibelanjakan Bazel selama pemanggilan.
Secara {i>default<i}, untuk semua perintah dan kueri seperti {i>build<i}, Bazel menulis profil seperti itu ke
command.profile.gz
dalam basis output. Anda dapat mengonfigurasi apakah profil
yang ditulis dengan
--generate_json_trace_profile
penanda, dan lokasi tempatnya ditulis dengan
flag --profile
. Lokasi yang berakhiran .gz
adalah
dikompresi dengan GZIP.
Alat
Anda dapat memuat profil ini ke chrome://tracing
atau menganalisis dan
pascapemrosesannya dengan alat lain.
chrome://tracing
Untuk memvisualisasikan profil, buka chrome://tracing
di tab browser Chrome,
klik "Muat" dan pilih file profil (yang mungkin dikompresi). Untuk selengkapnya
hasil yang mendetail, klik kotak di sudut kiri bawah.
Contoh profil:
Gambar 1. Contoh profil.
Anda dapat menggunakan kontrol keyboard ini untuk menavigasi:
- Tekan
1
untuk "pilih" mode. Dalam mode ini, Anda dapat memilih kotak tertentu untuk memeriksa detail acara (lihat pojok kiri bawah). Pilih beberapa peristiwa untuk mendapatkan statistik gabungan dan ringkasan. - Tekan
2
untuk "geser" mode. Kemudian tarik mouse untuk menggerakkan tampilan. Anda juga dapat menggunakana
/d
untuk berpindah ke kiri/kanan. - Tekan
3
untuk "zoom" mode. Lalu, tarik mouse untuk melakukan zoom. Anda dapat juga gunakanw
/s
untuk memperbesar/memperkecil. - Tekan
4
untuk "waktu" mode yang memungkinkan Anda mengukur jarak di antara dua peristiwa. - Tekan
?
untuk mempelajari semua kontrol.
bazel analyze-profile
Subperintah Bazel analyze-profile
menggunakan format profil dan mencetak statistik kumulatif untuk
jenis tugas yang berbeda untuk setiap fase pembangunan
dan analisis jalur kritis.
Misalnya, perintah
$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz
dapat menghasilkan output dalam bentuk ini:
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
Open source Penganalisis Pemanggilan Bazel menggunakan format profil dan mencetak saran tentang cara meningkatkan performa build tersebut. 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 mewakili Bazel utas dan peristiwa yang sesuai, tetapi beberapa baris khusus juga disertakan.
Baris khusus yang disertakan bergantung pada versi Bazel yang dipanggil saat profil dibuat, dan dapat disesuaikan menurut tanda yang berbeda.
Gambar 1 menunjukkan profil yang dibuat dengan Bazel v5.3.1 dan menyertakan baris-baris ini:
action count
: Menampilkan jumlah tindakan serentak yang sedang berlangsung. Klik untuk melihat nilai sebenarnya. Harus mencapai nilai--jobs
di bersih build yang berbeda.CPU usage (Bazel)
: Untuk setiap detik build, menampilkan jumlah CPU yang digunakan oleh Bazel (nilai 1 sama dengan satu core yang 100% sibuk).Critical Path
: Menampilkan satu blok untuk setiap tindakan di jalur penting.Main Thread
: Thread utama Bazel. Berguna untuk mendapatkan gambaran tingkat tinggi tentang apa yang dilakukan Bazel, misalnya "Luncurkan Blaze", "EvaluateTargetPatterns", dan "runAnalysisPhase".Garbage Collector
: Menampilkan Pengumpulan Sampah (GC) minor dan besar beberapa saat.
Masalah performa umum
Saat menganalisis profil performa, cari:
- Fase analisis lebih lambat dari yang diharapkan (
runAnalysisPhase
), terutama pada build inkremental. Hal ini bisa menjadi tanda implementasi aturan yang buruk, untuk contoh yang meratakan depset. Pemuatan paket dapat menjadi lambat oleh jumlah target yang berlebihan, makro kompleks atau glob rekursif. - Tindakan lambat individual, terutama yang berada di jalur kritis. Mungkin
untuk membagi tindakan besar menjadi beberapa tindakan yang lebih kecil atau mengurangi
sekumpulan dependensi (transitif)
untuk mempercepatnya. Periksa juga untuk mengidentifikasi
tinggi non-
PROCESS_TIME
(sepertiREMOTE_SETUP
atauFETCH
). - {i>Botttlenecks<i}, yaitu sejumlah kecil {i>thread<i} yang sibuk sementara yang lain menganggur / menunggu hasilnya (lihat sekitar 22s dan 29s pada Gambar 1). Mengoptimalkan fungsi ini kemungkinan besar akan memerlukan tindakan untuk menyentuh penerapan aturan atau Bazel untuk memperkenalkan lebih banyak paralelisme. Ini juga dapat terjadi ketika ada jumlah GC yang tidak biasa.
Format file profil
Objek tingkat teratas berisi metadata (otherData
) dan data pelacakan yang sebenarnya
(traceEvents
). Metadata berisi info 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
dalam mikrodetik. Kategori (cat
) adalah salah satu nilai enum ProfilerTask
.
Perhatikan bahwa beberapa peristiwa akan digabungkan jika durasinya sangat singkat dan mendekati
satu sama lain; izin lewat
--noslim_profile
jika Anda ingin mencegah penggabungan peristiwa.
Lihat juga Spesifikasi Format Peristiwa Rekaman Aktivitas Chrome.