Hồ sơ theo dõi JSON có thể rất hữu ích trong việc nhanh chóng hiểu được Bazel đã dành thời gian vào những gì trong khi gọi.
Theo mặc định, đối với tất cả các lệnh tương tự như bản dựng và truy vấn, Bazel sẽ ghi một hồ sơ như vậy vào command.profile.gz. Bạn có thể định cấu hình liệu một hồ sơ có được ghi bằng cờ --generate_json_trace_profile hay không, cũng như vị trí mà hồ sơ đó được ghi bằng cờ --profile. Những vị trí kết thúc bằng .gz được nén bằng GZIP. Sử dụng cờ --experimental_announce_profile_path để in đường dẫn đến tệp này vào 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à xử lý sau bằng các công cụ khác.
chrome://tracing
Để trực quan hoá hồ sơ, hãy mở chrome://tracing trong thẻ của 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). Để xem kết quả chi tiết hơn, hãy nhấp vào các hộp ở góc dưới bên trái.
Hồ sơ mẫu:
Hình 1. Hồ sơ mẫu.
Bạn có thể sử dụng các chế độ điều khiển sau bằng bàn phím để di chuyển:
- Nhấn
1để xem chế độ "chọn". Trong 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 để nhận bản tóm tắt và số liệu thống kê tổng hợp. - Nhấn
2để xem chế độ "kéo". Sau đó, kéo chuột để di chuyển khung hiển thị. Bạn cũng có thể dùnga/dđể di chuyển sang trái/phải. - Nhấn
3để dùng chế độ "thu phóng". Sau đó, kéo chuột để thu phóng. Bạn cũng có thể sử dụngw/sđể phóng to/thu nhỏ. - Nhấn
4để dùng chế độ "đặt thời gian". Chế độ này có thể đo khoảng cách giữa hai sự kiện. - Nhấn
?để tìm hiểu về tất cả các chế độ điều khiển.
bazel analyze-profile
Lệnh con Bazel analyze-profile sử dụng một đị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 trong từng giai đoạn xây dựng và bản phân tích đường dẫn quan trọng.
Ví dụ: lệnh
$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz
có thể mang lại 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ệnh gọi Bazel
Trình phân tích yêu cầu Bazel nguồn mở sử dụng một định dạng hồ sơ và in các đề 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 việc phân tích này bằng CLI hoặc tại 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 thực thi hành động cục bộ:
$ 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, một số lượng lớn hàng đại diện cho các luồng Bazel và các sự kiện tương ứng, nhưng cũng có một số hàng đặc biệt.
Các hàng đặc biệt trong đó phụ thuộc vào phiên bản Bazel được gọi khi tạo hồ sơ và có thể được tuỳ chỉnh bằng các cờ khác nhau.
Hình 1 hiển thị một hồ sơ đượ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 đang diễn ra. Hãy nhấp vào để xem giá trị thực tế. Nên tăng lên đến giá trị của--jobstrong bản dựng sạch.CPU usage (Bazel): Đối với mỗi giây của bản dựng, hãy hiển thị lượng CPU mà Bazel đã sử dụng (giá trị 1 tương đương với một lõi đang 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: Nội dung chính của Bazel. Hữu ích để có được thông tin tổng quan về những việc Bazel đang làm, ví dụ: "Launch Blaze", "measurementTargetPatterns" và "runAnalysisGiai đoạn".Garbage Collector: Hiển thị các lần tạm dừng thu gom rác (GC) nhỏ và lớn.
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 hiểu những thông tin sau:
- Giai đoạn phân tích chậm hơn 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 của việc triển khai quy tắc kém, ví dụ: làm phẳng các phần phụ thuộc. Quá trình tải gói có thể bị chậm do số lượng mục tiêu quá mức, macro phức tạp hoặc khối cầu đệ quy. - Từng thao tác chậm riêng lẻ, đặc biệt là những thao tác trên lộ trình quan trọng. Bạn 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ập hợp các phần phụ thuộc (bắc cầu) để tăng tốc độ. Ngoài ra, hãy kiểm tra xem có giá trị cao bất thường nào không phải là
PROCESS_TIME(chẳng hạn nhưREMOTE_SETUPhoặcFETCH). - Điểm tắc nghẽn, tức là một số lượng nhỏ luồng bận trong khi tất cả những luồng khác đang rảnh / chờ kết quả (xem khoảng 22 giây và 29 giây trong Hình 1). Để tối ưu hoá việc này, rất có thể bạn sẽ phải triển khai các quy tắc hoặc chính Bazel để tạo ra tính song song nhiều 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 cấu hình
Đố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, ví dụ như mã nhận dạng 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 tính 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 nhau; hãy 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 của Chrome Trace.