JSON İzleme Profili

Sorun bildir Kaynağı göster

JSON iz profili, Bazel'ın çağrı sırasında ne üzerinde zaman geçirdiğini hızlı bir şekilde anlamak için çok yararlı olabilir.

Varsayılan olarak, tüm derleme benzeri komutlar ve sorgu için Bazel böyle bir profili command.profile.gz adresine yazar. Bir profilin --generate_json_trace_profile işaretiyle yazılıp yazılmayacağını ve hangi konuma --profile işaretiyle yazılacağını 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 --experimental_announce_profile_path işaretini kullanın.

Araçlar

Bu profili chrome://tracing platformuna yükleyebilir veya diğer araçlarla analiz edip işleyebilirsiniz.

chrome://tracing

Profili görselleştirmek için Chrome tarayıcı sekmesinde chrome://tracing uygulamasını 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:

Örnek profil

Şekil 1. Örnek profil.

Gezinmek için şu klavye denetimlerini kullanabilirsiniz:

  • "Seç" modu için 1 tuş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 istatistikleri almak için birden fazla etkinlik seçin.
  • "Kaydırma" modu için 2 tuşuna basın. Ardından görünümü taşımak için fareyi sürükleyin. Sola/sağa gitmek için a/d tuşunu da kullanabilirsiniz.
  • "Yakınlaştırma" modu için 3 tuşuna basın. Ardından yakınlaştırmak için fareyi sürükleyin. Yakınlaştırmak/uzaklaştırmak için de w/s kullanabilirsiniz.
  • İki etkinlik arasındaki mesafeyi ölçebileceğiniz "zamanlama" modu için 4 tuş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 ve her derleme aşaması için farklı görev türlerine ait kümülatif istatistikleri ve kritik yolun analizini yazdırır.

Örneğin,

$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz

şu formun çıktısını 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 kaynaklı Bazel Invocation Analiz Aracı bir profil biçimini kullanır ve derlemenin performansını nasıl iyileştireceğinize dair önerileri yazdırır. Bu analiz, KSA kullanılarak veya https://analyzer.engflow.com adresinde gerçekleştirilebilir.

jq

jq, JSON verileri için sed gibidir. Yerel işlem yürütmede korumalı alan oluşturma adımının tüm sürelerini ayıklamak için jq kullanımıyla ilgili bir örnek:

$ 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 çok satır içeriyor. Satırlar genellikle toplu olarak Bazel ileti dizilerini 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ı bayraklarla özelleştirilebilir.

Şekil 1'de, Bazel 5.3.1 sürümüyle oluşturulmuş ve şu satırları içeren bir profil gösterilmektedir:

  • action count: Yayın sırasındaki eşzamanlı işlem sayısını gösterir. Gerçek değeri görmek için üzerini tıklayın. Temiz derlemelerde --jobs değerine kadar yükselmelidir.
  • CPU usage (Bazel): Derlemenin her saniyesi için Bazel tarafından kullanılan CPU miktarını görüntüler (1 değeri, bir çekirdeğin% 100 meşgul olduğu anlamına gelir).
  • Critical Path: Kritik yoldaki her işlem için bir blok görüntüler.
  • Main Thread: Bazel'ın ana ileti dizisi. Bazel'ın neler yaptığına dair genel bir fikir edinmek için yararlıdır; örneğin, "Launch Blaze", "evaluateTargetPatterns" ve "runAnalysisPhase".
  • Garbage Collector: Küçük ve önemli Çöp Toplama (GC) duraklarını gösterir.

Sık karşılaşılan performans sorunları

Performans profillerini analiz ederken şunlara bakın:

  • Özellikle artımlı derlemelerde, beklenenden daha yavaş analiz aşaması (runAnalysisPhase). Bu, kötü bir kuralın (örneğin, alt çizgileri düzelten bir uygulama) kötü bir uygulamaya işaret edebilir. Paket yükleme; aşırı miktarda hedef, karmaşık makro veya yinelenen küre nedeniyle yavaş olabilir.
  • Ayrı ayrı yavaş işlemler, özellikle kritik yoldakiler. Büyük işlemleri birden çok küçük işleme bölmek veya bunları hızlandırmak için (geçişli) bağımlılık grubunu azaltmak mümkün olabilir. PROCESS_TIME olmayan olağandışı bir yüksek değer olup olmadığını da kontrol edin (REMOTE_SETUP veya FETCH gibi).
  • Performans sorunları, diğer tüm iş parçacıkları boşta kalırken / sonucu beklerken az sayıda iş parçacığının meşgul olması anlamına gelir (Şekil 1'de 22'ler ve 29'lar civarında). Bunu optimize etmek, büyük olasılıkla daha fazla paralellik sağlamak için kural uygulamalarına veya Bazel'in kendisine dokunmayı gerektirecektir. Olağan dışı miktarda GC olduğunda da bu durum görülebilir.

Profil dosyası biçimi

Üst düzey nesne, meta verileri (otherData) ve gerçek izleme verilerini (traceEvents) içerir. Meta veriler, Bazel çağrısının çağrı kimliği ve tarihi gibi ekstra bilgiler 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},
 ]
}

İz etkinliklerindeki zaman damgaları (ts) ve süreler (dur) mikrosaniye cinsinden verilir. Kategori (cat), ProfilerTask enum değerlerinden biridir. Bazı etkinliklerin çok kısa ve birbirlerine yakın olmaları durumunda birleştirildiğini unutmayın. Etkinliklerin birleştirilmesini önlemek istiyorsanız --noslim_profile değerini iletin.

Chrome Trace Etkinlik Biçimi Spesifikasyonu'nu da inceleyin.