JSON ट्रेस प्रोफ़ाइल, यह समझने में काफ़ी मददगार साबित हो सकती है कि Bazel ने इनवोकेशन के दौरान किस काम में कितना समय लगाया.
डिफ़ॉल्ट रूप से, Bazel, बिल्ड जैसे सभी कमांड और क्वेरी के लिए, आउटपुट बेस में
command-$INOVCATION_ID.profile.gz नाम की एक प्रोफ़ाइल लिखता है. यहां
$INOVCATION_ID कमांड का इनवोकेशन आइडेंटिफ़ायर है. Bazel, आउटपुट बेस में command.profile.gz नाम का एक सिमलिंक भी बनाता है. यह सिमलिंक, सबसे नए कमांड की प्रोफ़ाइल की ओर इशारा करता है. आपके पास यह कॉन्फ़िगर करने का विकल्प होता है कि
--generate_json_trace_profile
फ़्लैग के साथ कोई प्रोफ़ाइल लिखी जाए या नहीं. साथ ही,
--profile फ़्लैग की मदद से, यह भी कॉन्फ़िगर किया जा सकता है कि प्रोफ़ाइल किस जगह लिखी जाए. .gz से खत्म होने वाली जगहों को
GZIP से कंप्रेस किया जाता है. Bazel, पोस्ट-बिल्ड विश्लेषण के लिए, डिफ़ॉल्ट रूप से आउटपुट बेस में पिछली पांच प्रोफ़ाइलें सेव रखता है.
--profiles_to_retain,
प्रोफ़ाइल का पाथ, --profile के साथ साफ़ तौर पर पास करने पर, गार्बेज कलेक्शन की प्रोसेस अपने-आप बंद हो जाती है.
टूल
इस प्रोफ़ाइल को chrome://tracing में लोड किया जा सकता है. इसके अलावा, इसे अन्य टूल की मदद से ऐनलाइज़ और पोस्ट-प्रोसेस भी किया जा सकता है.
chrome://tracing
प्रोफ़ाइल को विज़ुअलाइज़ करने के लिए, Chrome ब्राउज़र टैब में chrome://tracing खोलें. इसके बाद, "लोड करें" पर क्लिक करें और (कंप्रेस की गई) प्रोफ़ाइल फ़ाइल चुनें. ज़्यादा जानकारी वाले नतीजे देखने के लिए, नीचे बाईं ओर मौजूद बॉक्स पर क्लिक करें.
प्रोफ़ाइल का उदाहरण:
पहली इमेज. प्रोफ़ाइल का उदाहरण.
नेविगेट करने के लिए, कीबोर्ड के इन कंट्रोल का इस्तेमाल किया जा सकता है:
- "चुनें" मोड के लिए,
1दबाएं. इस मोड में, इवेंट की जानकारी देखने के लिए, खास बॉक्स चुने जा सकते हैं. ज़्यादा जानकारी के लिए, नीचे बाईं ओर देखें. खास जानकारी और एग्रीगेट किए गए आंकड़े पाने के लिए, एक से ज़्यादा इवेंट चुनें. - "पैन" मोड के लिए,
2दबाएं. इसके बाद, व्यू को घुमाने के लिए, माउस को खींचें. बाएं/दाएं जाने के लिए,a/dका भी इस्तेमाल किया जा सकता है. - "ज़ूम" मोड के लिए,
3दबाएं. इसके बाद, ज़ूम करने के लिए, माउस को खींचें. ज़ूम इन/आउट करने के लिए,w/sका भी इस्तेमाल किया जा सकता है. - "टाइमिंग" मोड के लिए,
4दबाएं. इस मोड में, दो इवेंट के बीच की दूरी मेज़र की जा सकती है. - सभी कंट्रोल के बारे में जानने के लिए,
?दबाएं.
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 Invocation Analyzer
ओपन-सोर्स Bazel Invocation Analyzer प्रोफ़ाइल फ़ॉर्मैट का इस्तेमाल करता है. साथ ही, यह बिल्ड की परफ़ॉर्मेंस बेहतर बनाने के तरीके के बारे में सुझाव दिखाता है. यह विश्लेषण, इसके सीएलआई का इस्तेमाल करके या https://analyzer.engflow.com पर किया जा सकता है.
jq
jq, JSON डेटा के लिए sed की तरह काम करता है. लोकल ऐक्शन के एक्ज़ीक्यूशन में, सैंडबॉक्स बनाने के चरण की सभी अवधियां निकालने के लिए, 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 के वर्शन पर निर्भर करती हैं. इन्हें अलग-अलग फ़्लैग की मदद से पसंद के मुताबिक बनाया जा सकता है.
पहली इमेज में, Bazel के वर्शन 5.3.1 से बनाई गई प्रोफ़ाइल दिखाई गई है. इसमें ये लाइनें शामिल हैं:
action count: इससे पता चलता है कि एक साथ कितनी कार्रवाइयां चल रही थीं. असल वैल्यू देखने के लिए, इस पर क्लिक करें. क्लीन बिल्ड में, इसकी वैल्यू--jobsकी वैल्यू के बराबर होनी चाहिए.CPU usage (Bazel): इससे पता चलता है कि बिल्ड के हर सेकंड में, Bazel ने कितना सीपीयू इस्तेमाल किया. वैल्यू 1 का मतलब है कि एक कोर 100% व्यस्त है.Critical Path: इससे अहम पाथ पर मौजूद हर कार्रवाई के लिए एक ब्लॉक दिखता है.Main Thread: यह Bazel का मुख्य थ्रेड है. इससे यह समझने में मदद मिलती है कि Bazel क्या कर रहा है. उदाहरण के लिए, "Launch Blaze", "evaluateTargetPatterns" और "runAnalysisPhase".Garbage Collector: इससे माइनर और मेजर गार्बेज कलेक्शन (जीसी) पॉज़ दिखते हैं.
परफ़ॉर्मेंस से जुड़ी सामान्य समस्याएं
परफ़ॉर्मेंस प्रोफ़ाइल का विश्लेषण करते समय, इन चीज़ों पर ध्यान दें:
- विश्लेषण फ़ेज़ (
runAnalysisPhase) उम्मीद से ज़्यादा समय ले रहा है. खास तौर पर, इंक्रीमेंटल बिल्ड में. यह खराब तरीके से लागू किए गए नियम का संकेत हो सकता है. उदाहरण के लिए, ऐसा नियम जो depsets को फ़्लैट करता है. ज़्यादा टारगेट, जटिल मैक्रो या रिकर्सिव ग्लोब की वजह से, पैकेज लोड होने में ज़्यादा समय लग सकता है. - कुछ कार्रवाइयों में ज़्यादा समय लग रहा है. खास तौर पर, अहम पाथ पर मौजूद कार्रवाइयों में. ज़्यादा समय लेने वाली कार्रवाइयों को कई छोटी कार्रवाइयों में बांटा जा सकता है या उन्हें तेज़ करने के लिए, (ट्रांज़िटिव) डिपेंडेंसी का सेट कम किया जा सकता है. इसके अलावा,
PROCESS_TIMEके अलावा, किसी अन्य चीज़ में ज़्यादा समय लगने की समस्या भी देखें. जैसे,REMOTE_SETUPयाFETCH. - बॉटलनेक. इसका मतलब है कि कुछ थ्रेड व्यस्त हैं, जबकि बाकी सभी आइडल हैं या नतीजे का इंतज़ार कर रहे हैं. ज़्यादा जानकारी के लिए, पहली इमेज में 22वें और 29वें सेकंड के आस-पास देखें. इसे ऑप्टिमाइज़ करने के लिए, ज़्यादातर मामलों में नियम लागू करने या Bazel में बदलाव करना होगा, ताकि ज़्यादा पैरललिज़म लाया जा सके. ऐसा तब भी हो सकता है, जब जीसी में ज़्यादा समय लग रहा हो.
प्रोफ़ाइल फ़ाइल फ़ॉर्मैट
सबसे ऊपर मौजूद ऑब्जेक्ट में, मेटाडेटा (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), ProfilerTask की enum वैल्यू में से एक होती है.
ध्यान दें कि कुछ इवेंट को एक साथ मर्ज कर दिया जाता है, अगर वे बहुत कम समय के लिए होते हैं और एक-दूसरे के आस-पास होते हैं
. अगर आपको इवेंट मर्ज होने से रोकना है, तो --noslim_profile
पास करें.