JSON izleme profili, çağrı sırasında Bazel'in ne için zaman harcadığını hızlı bir şekilde anlamak açısından çok faydalı olabilir.
Varsayılan olarak, Bazel tüm derleme benzeri komutlar ve sorgular için bu tür bir profili command.profile.gz adresine yazar. Bir profilin --generate_json_trace_profile işaretiyle yazılıp yazılmayacağını ve --profile işaretiyle konumu yapılandırabilirsiniz. .gz ile biten konumlar GZIP ile sıkıştırılır. Bu dosyanın yolunu günlüğe yazdırmak için işareti --experimental_announce_profile_path kullanın.
Araçlar
Bu profili chrome://tracing hizmetine yükleyebilir veya
diğer araçlarla analiz edip işleyebilirsiniz.
chrome://tracing
Profili görselleştirmek için chrome://tracing adresini bir Chrome tarayıcı sekmesinde açın, "Yükle"yi tıklayın ve (potansiyel olarak sıkıştırılmış) profil dosyasını seçin. Daha ayrıntılı sonuçlar için sol alt köşedeki kutuları tıklayın.
Örnek profil:
Şekil 1. Örnek profil.
Gezinmek için şu klavye denetimlerini kullanabilirsiniz:
- "Seç" modu için
1tuşuna basın. Bu modda, etkinlik ayrıntılarını incelemek için belirli kutuları seçebilirsiniz (sol alt köşeye bakın). Özet ve toplu istatistikler almak için birden fazla etkinlik seçin. - "Kaydırma" modu için
2tuşlarına basın. Ardından görünümü hareket ettirmek için fareyi sürükleyin. Sağa/sola gitmek içina/dtuşlarını da kullanabilirsiniz. - "Yakınlaştırma" modu için
3tuşuna basın. Ardından, yakınlaştırmak için fareyi sürükleyin. Yakınlaştırmak/uzaklaştırmak içinw/stuşlarını da kullanabilirsiniz. - İki etkinlik arasındaki mesafeyi ölçebileceğiniz "zamanlama" modu için
4tuşuna basın. - Tüm kontroller hakkında bilgi edinmek için
?tuşuna basın.
bazel analyze-profile
Bazel alt komutu analyze-profile bir profil biçimi kullanır, her derleme aşaması için farklı görev türleri için kümülatif istatistikleri ve kritik yol analizini yazdırır.
Örneğin, komutlar
$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz
şu biçimde çıktılar verebilir:
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
Bazel Çağrı Analiz Aracı
Açık kaynak Bazel Invocation Analiz aracı, bir profil biçimi kullanır ve derlemenin performansını iyileştirmeyle ilgili önerileri yazdırır. Bu analiz, KSA kullanılarak veya https://analyzer.engflow.com adresinden yapılabilir.
jq
jq, JSON verileri için sed gibidir. Yerel işlem yürütülürken korumalı alan oluşturma adımının tüm sürelerini çıkarmak için jq kullanımı örneği:
$ 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
[...]
Profil bilgileri
Profil birden fazla satır içeriyor. Genellikle satırların toplu kısmı Bazel iş parçacıklarını ve bunlara karşılık gelen etkinlikleri temsil eder. Ancak bazı özel satırlar da dahil edilir.
Dahil edilen özel satırlar, profil oluşturulurken çağrılan Bazel sürümüne bağlıdır ve farklı işaretler tarafından özelleştirilebilir.
Şekil 1'de Bazel v5.3.1 ile oluşturulmuş bir profil gösterilmiştir ve aşağıdaki satırları içerir:
action count: Yayında olan eşzamanlı işlem sayısını gösterir. Gerçek değeri görmek için üzerini tıklayın. Temiz derlemelerde--jobsdeğerine kadar çıkmalıdır.CPU usage (Bazel): Derlemenin her saniyesi için Bazel tarafından kullanılan CPU miktarını gösterir (1 değeri, bir çekirdeğin% 100 meşgul olduğunu gösterir).Critical Path: Kritik yoldaki her işlem için bir blok görüntüler.Main Thread: Bazel'in ana ileti dizisi. Bazel'ın neler yaptığına dair genel bir fikir edinmek için kullanışlıdır. Örneğin, "Launch Blaze", "acceptTargetPatterns" ve "runAnalysisPhase".Garbage Collector: Küçük ve önemli Çöp Toplama (GC) duraklatmalarını gösterir.
Sık karşılaşılan performans sorunları
Performans profillerini analiz ederken şunlara dikkat edin:
- Özellikle artımlı derlemelerde, beklenenden daha yavaş analiz aşaması (
runAnalysisPhase). Bu, kuralın kötü bir şekilde uygulandığını, örneğin dendeki eksiklikleri giderdiğinin göstergesi olabilir. Paket yükleme işlemi, aşırı sayıda hedef, karmaşık makrolar veya özyinelemeli glob'lar nedeniyle yavaş olabilir. - Bağımsız yavaş işlemler, özellikle de kritik yoldakiler. Büyük işlemleri birden çok küçük eyleme bölmek veya bunları hızlandırmak için (geçişli) bağımlılıkları azaltmak mümkün olabilir. Ayrıca,
PROCESS_TIMEolmayan olağan dışı bir değer olup olmadığını kontrol edin (REMOTE_SETUPveyaFETCHgibi). - Diğerleri boşta kalırken / sonuç beklerken az sayıda iş parçacığı meşguldür (Şekil 1'deki yaklaşık 22 sn ve 29 saniyeye bakın). Bunu optimize etmek için, büyük olasılıkla kural uygulamalarına veya Bazel'e daha fazla benzerlik sağlamak amacıyla dokunmak gerekecektir. Olağan dışı miktarda GC olduğunda bu durum ortaya çıkabilir.
Profil dosya biçimi
Üst düzey nesne, meta verileri (otherData) ve gerçek izleme verilerini (traceEvents) içerir. Meta veri, ek bilgiler (ör. Bazel çağrısının tarihi ve çağrı kimliği) içerir.
Örnek:
{
"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},
]
}
İzleme etkinliklerindeki zaman damgaları (ts) ve süreler (dur) mikrosaniye cinsinden verilir. Kategori (cat), ProfilerTask enum değerlerinden biri.
Birbirine çok yakın ve çok kısa olan bazı etkinliklerin birleştirildiğini unutmayın. Etkinlik birleştirmeyi önlemek istiyorsanız --noslim_json_profile değerini iletin.
Ayrıca Chrome İzleme Etkinlik Biçimi Spesifikasyonu'na da bakın.