Hồ sơ theo dõi JSON

Báo cáo vấn đề Xem nguồn Hằng đêm · 7.3 · 7.2 · 7.1 · 7 · 6,5

Hồ sơ theo dõi JSON có thể rất hữu ích trong việc giúp bạn nhanh chóng nắm được những khoản chi tiêu của Bazel trong khi gọi.

Theo mặc định, đối với tất cả các lệnh và truy vấn giống bản dựng, Bazel sẽ ghi một hồ sơ như vậy vào command.profile.gz. Bạn có thể định cấu hình xem có viết hồ sơ bằng --generate_json_trace_profile cờ hiệu và vị trí được gắn cờ bằng Cờ --profile. Các vị trí kết thúc với .gz là được nén bằng GZIP. Sử dụng cờ --experimental_announce_profile_path để in đường dẫn đến tệp này ra nhật ký.

Công cụ

Bạn có thể tải hồ sơ này vào chrome://tracing hoặc phân tích và sau khi xử lý bằng các công cụ khác.

chrome://tracing

Để xem hình ảnh hồ sơ, hãy mở chrome://tracing trong thẻ trình duyệt Chrome. nhấp vào "Tải" và chọn tệp cấu hình (có thể được nén). Để biết thêm kết quả chi tiết, nhấp vào các hộp ở góc dưới bên trái.

Hồ sơ mẫu:

Hồ sơ mẫu

Hình 1. Hồ sơ mẫu.

Bạn có thể sử dụng các nút điều khiển bằng bàn phím sau để di chuyển:

  • Nhấn 1 để "chọn" . Ở chế độ này, bạn có thể chọn các hộp cụ thể để kiểm tra chi tiết sự kiện (xem góc dưới bên trái). Chọn nhiều sự kiện để xem bản tóm tắt và số liệu thống kê tổng hợp.
  • Nhấn 2 để "di chuyển" . Sau đó, kéo chuột để di chuyển khung hiển thị. Bạn cũng có thể sử dụng a/d để di chuyển sang trái/phải.
  • Nhấn 3 để "thu phóng" . Sau đó, kéo chuột để thu phóng. Bạn có thể cũng sử dụng w/s để phóng to/thu nhỏ.
  • Nhấn 4 để "đặt thời gian" cho phép bạn đo khoảng cách giữa hai sự kiện.
  • Nhấn ? để tìm hiểu về mọi chế độ điều khiển.

bazel analyze-profile

Lệnh con Bazel analyze-profile sử dụng định dạng hồ sơ và in số liệu thống kê tích luỹ cho các loại tác vụ khác nhau cho từng giai đoạn xây dựng và bản phân tích lộ trình quan trọng.

Ví dụ: các lệnh

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

có thể cho ra kết quả dạng này:

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

Trình phân tích lời gọi Bazel

Nguồn mở Trình phân tích lời gọi Bazel sử dụng định dạng hồ sơ và in đề xuất về cách cải thiện hiệu suất của bản dựng. Bạn có thể thực hiện phân tích này bằng CLI hoặc trên https://analyzer.engflow.com.

jq

jq giống như sed đối với dữ liệu JSON. Ví dụ về cách sử dụng jq để trích xuất tất cả thời lượng của bước tạo hộp cát trong quá trình thực thi hành động liên quan đến địa điểm thực tế:

$ 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
[...]

Thông tin hồ sơ

Hồ sơ chứa nhiều hàng. Thông thường, hàng loạt hàng đại diện cho Bazel luồng và các sự kiện tương ứng của chúng, nhưng cũng đưa vào một số hàng đặc biệt.

Các hàng đặc biệt được đưa vào sẽ phụ thuộc vào phiên bản Bazel được gọi khi đã được tạo và có thể được tuỳ chỉnh bằng các cờ khác nhau.

Hình 1 cho thấy một cấu hình được tạo bằng Bazel v5.3.1 và bao gồm các hàng sau:

  • action count: Hiển thị số lượng hành động đồng thời diễn ra. Nhấp chuột để xem giá trị thực tế. Sẽ tăng lên giá trị của Dọn sạch --jobs bản dựng.
  • CPU usage (Bazel): Cho mỗi giây của bản dựng, hiển thị số lượng CPU mà Bazel sử dụng (giá trị 1 tương đương với một lõi bận 100%).
  • Critical Path: Hiển thị một khối cho mỗi hành động trên đường dẫn quan trọng.
  • Main Thread: Luồng chính của Bazel. Hữu ích khi có được hình ảnh cấp cao của việc Bazel đang làm, ví dụ: "Launch Blaze", "measuringTargetPatterns", và "runAnalysisPhase".
  • Garbage Collector: Hiển thị Thu gom rác nhỏ và lớn (GC) tạm dừng.

Các vấn đề thường gặp về hiệu suất

Khi phân tích hồ sơ hiệu suất, hãy tìm kiếm:

  • Chậm hơn giai đoạn phân tích dự kiến (runAnalysisPhase), đặc biệt là trên các bản dựng tăng dần. Đây có thể là dấu hiệu cho thấy bạn đã triển khai quy tắc kém hiệu quả, ví dụ: làm phẳng phần phân tách. Quá trình tải gói có thể bị chậm do quá nhiều mục tiêu, macro phức tạp hoặc khối cầu quy đệ quy.
  • Từng hành động chậm, đặc biệt là những hành động trên lộ trình quan trọng. Có thể là có thể chia các hành động lớn thành nhiều hành động nhỏ hơn hoặc giảm để tăng tốc độ của chúng. Đồng thời kiểm tra xem có cao không phải PROCESS_TIME (chẳng hạn như REMOTE_SETUP hoặc FETCH).
  • Nút thắt cổ chai, tức là một số ít luồng bận rộn trong khi tất cả các luồng khác chạy không tải / chờ kết quả (xem khoảng 22 giây và 29 giây trong Hình 1). Để tối ưu hoá chỉ số này, rất có thể bạn sẽ phải chạm vào các hoạt động triển khai quy tắc hoặc chính Bazel để giới thiệu chủ đề song song hơn. Điều này cũng có thể xảy ra khi có một lượng GC bất thường.

Định dạng tệp hồ sơ

Đối tượng cấp cao nhất chứa siêu dữ liệu (otherData) và dữ liệu theo dõi thực tế (traceEvents). Siêu dữ liệu chứa thông tin bổ sung, chẳng hạn như mã lệnh gọi và ngày thực hiện lệnh gọi Bazel.

Ví dụ:

{
  "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},
 ]
}

Dấu thời gian (ts) và thời lượng (dur) trong các sự kiện theo dõi được cung cấp bằng micrô giây. Danh mục (cat) là một trong các giá trị enum của ProfilerTask. Xin lưu ý rằng một số sự kiện được hợp nhất với nhau nếu chúng rất ngắn và gần với với nhau; truyền --noslim_json_profile nếu bạn muốn ngăn việc hợp nhất sự kiện.

Xem thêm Thông số kỹ thuật về định dạng sự kiện theo dõi trong Chrome.