โปรไฟล์การติดตาม JSON มีประโยชน์มากในการทำความเข้าใจอย่างรวดเร็วว่า Bazel ใช้เวลาไปกับอะไรบ้างระหว่างการเรียกใช้
โดยค่าเริ่มต้น Bazel จะเขียนโปรไฟล์ลงใน
ฐานเอาต์พุตชื่อ command-$INVOCATION_ID.profile.gz สำหรับคำสั่งและการค้นหาที่คล้ายกับบิลด์ทั้งหมด โดยที่
$INVOCATION_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
ตัววิเคราะห์การเรียกใช้ 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 กำลังทำอยู่ เช่น "Launch Blaze", "evaluateTargetPatterns" และ "runAnalysisPhase"Garbage Collector: แสดงการหยุดชั่วคราวของการเก็บขยะ (GC) ระดับย่อยและระดับหลัก
ปัญหาด้านประสิทธิภาพที่พบบ่อย
เมื่อวิเคราะห์โปรไฟล์ประสิทธิภาพ ให้มองหาข้อมูลต่อไปนี้
- ระยะการวิเคราะห์ (
runAnalysisPhase) ช้ากว่าที่คาดไว้ โดยเฉพาะอย่างยิ่งในบิลด์แบบเพิ่ม ซึ่งอาจเป็นสัญญาณของการใช้งานกฎที่ไม่ดี เช่น การใช้งานที่ทำให้ depsets แบน การโหลดแพ็กเกจอาจช้าเนื่องจากมีเป้าหมายจำนวนมากเกินไป แมโครที่ซับซ้อน หรือ globs แบบเรียกซ้ำ - การดำเนินการแต่ละรายการช้า โดยเฉพาะอย่างยิ่งการดำเนินการในเส้นทางวิกฤต คุณอาจแยกการดำเนินการขนาดใหญ่ออกเป็นการดำเนินการขนาดเล็กลงหลายรายการ หรือลดชุดการขึ้นต่อกัน (แบบส่งผ่าน) เพื่อเพิ่มความเร็วได้ นอกจากนี้ ให้ตรวจสอบ
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
หากคุณต้องการป้องกันการผสานเหตุการณ์