โปรไฟล์การติดตาม JSON มีประโยชน์อย่างยิ่งในการทำความเข้าใจอย่างรวดเร็วว่า Bazel ใช้เวลาไปกับอะไรบ้างในระหว่างการเรียกใช้
โดยค่าเริ่มต้น สำหรับคำสั่งและการค้นหาที่คล้ายกับการสร้างทั้งหมด Bazel จะเขียนโปรไฟล์ลงใน
เอาต์พุตเบสที่มีชื่อว่า command-$INOVCATION_ID.profile.gz โดยที่
$INOVCATION_ID คือตัวระบุการเรียกใช้ของคำสั่ง นอกจากนี้ Bazel ยังสร้าง
ลิงก์สัญลักษณ์ชื่อ command.profile.gz ในเอาต์พุตเบสซึ่งชี้ไปยังโปรไฟล์
ของคำสั่งล่าสุดด้วย คุณสามารถกำหนดค่าได้ว่าจะเขียนโปรไฟล์ด้วยแฟล็ก
--generate_json_trace_profile
หรือไม่ และกำหนดตำแหน่งที่จะเขียนด้วยแฟล็ก
--profile การแชร์ตำแหน่งที่ลงท้ายด้วย .gz จะได้รับการบีบอัดด้วย GZIP Bazel จะเก็บโปรไฟล์ 5 รายการล่าสุด ซึ่งกำหนดค่าได้โดย
--profiles_to_retain
ในเอาต์พุตเบสโดยค่าเริ่มต้นสำหรับการวิเคราะห์หลังการสร้าง การส่งเส้นทางโปรไฟล์อย่างชัดเจนด้วย --profile จะปิดใช้การเก็บขยะอัตโนมัติ
เครื่องมือ
คุณสามารถโหลดโปรไฟล์นี้ลงใน chrome://tracing หรือวิเคราะห์และ
ประมวลผลภายหลังด้วยเครื่องมืออื่นๆ
chrome://tracing
หากต้องการแสดงภาพโปรไฟล์ ให้เปิด chrome://tracing ในแท็บเบราว์เซอร์ Chrome
คลิก "โหลด" แล้วเลือกไฟล์โปรไฟล์ (อาจมีการบีบอัด) หากต้องการดูผลลัพธ์ที่ละเอียดยิ่งขึ้น ให้คลิกช่องที่มุมซ้ายล่าง
ตัวอย่างโปรไฟล์
รูปที่ 1 ตัวอย่างโปรไฟล์
คุณใช้การควบคุมด้วยแป้นพิมพ์ต่อไปนี้เพื่อไปยังส่วนต่างๆ ได้
- กด
1เพื่อเข้าสู่โหมด "เลือก" ในโหมดนี้ คุณสามารถเลือก ช่องที่ต้องการเพื่อตรวจสอบรายละเอียดเหตุการณ์ (ดูมุมซ้ายล่าง) เลือกหลายกิจกรรมเพื่อดูข้อมูลสรุปและสถิติแบบรวม - กด
2เพื่อเข้าสู่โหมด "เลื่อน" จากนั้นลากเมาส์เพื่อย้ายมุมมอง นอกจากนี้ คุณยังใช้a/dเพื่อเลื่อนไปทางซ้าย/ขวาได้ด้วย - กด
3เพื่อเข้าสู่โหมด "ซูม" จากนั้นลากเมาส์เพื่อซูม นอกจากนี้ คุณยังใช้w/sเพื่อซูมเข้า/ออกได้ด้วย - กด
4เพื่อเข้าสู่โหมด "เวลา" ซึ่งคุณจะวัดระยะทาง ระหว่างเหตุการณ์ 2 เหตุการณ์ได้ - กด
?เพื่อดูข้อมูลเกี่ยวกับการควบคุมทั้งหมด
bazel analyze-profile
คำสั่งย่อยของ Bazel analyze-profile
จะใช้รูปแบบโปรไฟล์และพิมพ์สถิติสะสมสำหรับ
ประเภทงานต่างๆ สำหรับแต่ละเฟสของการบิลด์และการวิเคราะห์เส้นทางวิกฤต
เช่น คำสั่ง
$ bazel build --profile=/tmp/profile.gz //path/to:target
...
$ bazel analyze-profile /tmp/profile.gz
อาจให้ผลลัพธ์ในรูปแบบนี้
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
เครื่องมือวิเคราะห์การเรียกใช้ Bazel แบบโอเพนซอร์ส ใช้รูปแบบโปรไฟล์และพิมพ์คำแนะนำเกี่ยวกับวิธีปรับปรุง ประสิทธิภาพการสร้าง คุณสามารถทำการวิเคราะห์นี้ได้โดยใช้ CLI หรือที่ https://analyzer.engflow.com
jq
jq เหมือนกับ sed สำหรับข้อมูล JSON ตัวอย่างการใช้งาน jq เพื่อดึงข้อมูลระยะเวลาทั้งหมด
ของขั้นตอนการสร้างแซนด์บ็อกซ์ในการดำเนินการการกระทำเกี่ยวกับสถานที่
$ 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
[...]
ข้อมูลโปรไฟล์
โปรไฟล์มีหลายแถว โดยปกติแล้ว แถวส่วนใหญ่จะแสดงเธรด Bazel และเหตุการณ์ที่เกี่ยวข้อง แต่ก็มีแถวพิเศษบางแถวรวมอยู่ด้วย
แถวพิเศษที่รวมไว้จะขึ้นอยู่กับเวอร์ชันของ Bazel ที่เรียกใช้เมื่อสร้างโปรไฟล์ และอาจปรับแต่งได้ด้วยแฟล็กต่างๆ
รูปที่ 1 แสดงโปรไฟล์ที่สร้างด้วย Bazel v5.3.1 และมีแถวต่อไปนี้
action count: แสดงจำนวนการดำเนินการพร้อมกันที่กำลังดำเนินการอยู่ คลิก เพื่อดูค่าจริง ควรมีค่าไม่เกิน--jobsในการสร้าง ที่สะอาดCPU usage (Bazel): แสดงปริมาณ CPU ที่ Bazel ใช้ในแต่ละวินาทีของการบิลด์ (ค่า 1 หมายถึง 1 คอร์ทำงาน 100%)Critical Path: แสดงบล็อก 1 บล็อกสําหรับการดําเนินการแต่ละอย่างในเส้นทางวิกฤตMain Thread: เทรดหลักของ Bazel มีประโยชน์ในการดูภาพรวมของสิ่งที่ Bazel กำลังทำอยู่ เช่น "เปิดตัว Blaze" "evaluateTargetPatterns" และ "runAnalysisPhase"Garbage Collector: แสดงการหยุดชั่วคราวของการเก็บขยะ (GC) ขนาดเล็กและขนาดใหญ่
ปัญหาด้านประสิทธิภาพที่พบบ่อย
เมื่อวิเคราะห์โปรไฟล์ประสิทธิภาพ ให้มองหาสิ่งต่อไปนี้
- ระยะการวิเคราะห์ช้ากว่าที่คาดไว้ (
runAnalysisPhase) โดยเฉพาะอย่างยิ่งในการสร้างแบบเพิ่ม ซึ่งอาจเป็นสัญญาณของการใช้กฎที่ไม่ดี เช่น กฎที่ทำให้ Depset แบน การโหลดแพ็กเกจอาจช้าเนื่องจากมีเป้าหมายมากเกินไป แมโครที่ซับซ้อน หรือ Glob แบบเรียกซ้ำ - การดำเนินการที่ช้าแต่ละรายการ โดยเฉพาะการดำเนินการในเส้นทางวิกฤต คุณอาจแบ่งการดำเนินการขนาดใหญ่ออกเป็นการดำเนินการขนาดเล็กหลายรายการ หรือลดชุดการอ้างอิง (แบบทรานซิทีฟ) เพื่อเพิ่มความเร็วได้ นอกจากนี้ ให้ตรวจสอบว่ามี
PROCESS_TIMEสูงผิดปกติ หรือไม่ (เช่นREMOTE_SETUPหรือFETCH) - คอขวด ซึ่งก็คือมีเธรดจำนวนน้อยที่ทำงานอยู่ขณะที่เธรดอื่นๆ ทั้งหมด ไม่ได้ใช้งาน / รอผลลัพธ์ (ดูที่ประมาณ 22 วินาทีและ 29 วินาทีในรูปที่ 1) การเพิ่มประสิทธิภาพนี้มักจะต้องมีการแตะการใช้งานกฎ หรือ Bazel เองเพื่อเพิ่มความขนาน กรณีนี้อาจเกิดขึ้นได้เช่นกันเมื่อ มีการรวบรวมขยะ (GC) มากผิดปกติ
รูปแบบไฟล์โปรไฟล์
ออบเจ็กต์ระดับบนสุดมีข้อมูลเมตา (otherData) และข้อมูลการติดตามจริง
(traceEvents) ข้อมูลเมตามีข้อมูลเพิ่มเติม เช่น รหัสการเรียกใช้
และวันที่ของการเรียกใช้ Bazel
ตัวอย่าง
{
"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},
]
}
การประทับเวลา (ts) และระยะเวลา (dur) ในเหตุการณ์การติดตามจะระบุเป็นหน่วยไมโครวินาที
หมวดหมู่ (cat) เป็นค่า enum ค่าหนึ่งของ ProfilerTask
โปรดทราบว่าระบบจะผสานเหตุการณ์บางอย่างเข้าด้วยกันหากเหตุการณ์นั้นสั้นมากและอยู่ใกล้กัน
ส่ง
--noslim_profile
หากคุณต้องการป้องกันไม่ให้ระบบผสานเหตุการณ์