सिस्ट्रेस को समझना

Android डिवाइस की परफ़ॉर्मेंस का विश्लेषण करने के लिए, systrace एक मुख्य टूल है. हालांकि, यह असल में अन्य टूल के लिए एक रैपर है. यह atrace के आस-पास मौजूद होस्ट-साइड रैपर है. यह डिवाइस-साइड एक्ज़ीक्यूटेबल है, जो यूज़रस्पेस ट्रैकिंग को कंट्रोल करता है और ftrace को सेट अप करता है. साथ ही, यह Linux कर्नेल में प्राइमरी ट्रैकिंग मैकेनिज्म भी है. systrace, ट्रैकिंग चालू करने के लिए atrace का इस्तेमाल करता है. इसके बाद, ftrace बफ़र को पढ़ता है और इसे एक अलग HTML व्यूअर में रैप करता है. (नए कर्नेल में, Linux एन्हैंस्ड बर्कले पैकेट फ़िल्टर (eBPF) के लिए सहायता उपलब्ध है. हालांकि, यहां दिया गया दस्तावेज़ 3.18 कर्नेल (eFPF नहीं) से जुड़ा है, क्योंकि Pixel/Pixel XL पर इसका इस्तेमाल किया गया था.)

systrace का मालिकाना हक, Google Android और Google Chrome की टीमों के पास है. साथ ही, यह Catapult प्रोजेक्ट का हिस्सा होने के नाते ओपन सोर्स है. systrace के अलावा, Catapult में अन्य काम की सुविधाएं भी शामिल हैं. उदाहरण के लिए, systrace या atrace की तुलना में ftrace में ज़्यादा सुविधाएं होती हैं. साथ ही, इसमें कुछ बेहतर सुविधाएं भी होती हैं, जो परफ़ॉर्मेंस से जुड़ी समस्याओं को डीबग करने के लिए ज़रूरी होती हैं. (इन सुविधाओं के लिए, रूट ऐक्सेस और अक्सर नया कर्नेल ज़रूरी होता है.)

systrace चलाना

Pixel/Pixel XL पर, फ़्रेम रेट में उतार-चढ़ाव की समस्या को डीबग करते समय, इस कमांड से शुरू करें:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

जीपीयू और डिसप्ले पाइपलाइन गतिविधि के लिए ज़रूरी अतिरिक्त ट्रेसपॉइंट के साथ जोड़ने पर, आपको उपयोगकर्ता के इनपुट से स्क्रीन पर दिखाए गए फ़्रेम तक ट्रेस करने की सुविधा मिलती है. इवेंट को मिटाने से बचने के लिए, बफ़र का साइज़ बड़ा सेट करें. ऐसा इसलिए, क्योंकि बड़े बफ़र के बिना, कुछ सीपीयू में ट्रेस के कुछ समय बाद कोई इवेंट नहीं होता.

systrace का इस्तेमाल करते समय, ध्यान रखें कि हर इवेंट, सीपीयू पर किसी चीज़ की वजह से ट्रिगर होता है.

systrace, ftrace के ऊपर बनाया गया है और ftrace, सीपीयू पर चलता है. इसलिए, सीपीयू पर कुछ ऐसा होना चाहिए जो ftrace बफ़र को लिखे, जो हार्डवेयर में हुए बदलावों को लॉग करता है. इसका मतलब है कि अगर आपको यह जानना है कि डिसप्ले फ़ेंस की स्थिति क्यों बदली, तो ट्रांज़िशन के ठीक उसी समय सीपीयू पर चल रही प्रोसेस देखी जा सकती है. सीपीयू पर चल रही किसी प्रोसेस की वजह से, लॉग में बदलाव हुआ था. systrace का इस्तेमाल करके परफ़ॉर्मेंस का विश्लेषण करने के लिए, यह कॉन्सेप्ट ज़रूरी है.

उदाहरण: काम करने वाला फ़्रेम

इस उदाहरण में, सामान्य यूज़र इंटरफ़ेस (यूआई) पाइपलाइन के लिए systrace के बारे में बताया गया है. उदाहरण के साथ-साथ, ट्रैक के बारे में जानने के लिए, ट्रैक की ज़िप फ़ाइल डाउनलोड करें. इसमें इस सेक्शन में बताए गए अन्य ट्रैक भी शामिल हैं. इसके बाद, फ़ाइल को अनज़िप करें और systrace_tutorial.html फ़ाइल को अपने ब्राउज़र में खोलें. ध्यान रखें कि यह systrace एक बड़ी फ़ाइल है. अगर आपने अपने रोज़ के काम में systrace का इस्तेमाल नहीं किया है, तो हो सकता है कि यह बहुत बड़ा ट्रैक हो. इसमें आपको एक ट्रैक में जितनी जानकारी दिखती है उससे ज़्यादा जानकारी दिख सकती है.

TouchLatency जैसे लगातार और समय-समय पर होने वाले वर्कलोड के लिए, यूज़र इंटरफ़ेस (यूआई) पाइपलाइन में ये चीज़ें शामिल होती हैं:

  1. SurfaceFlinger में मौजूद EventThread, ऐप्लिकेशन के यूज़र इंटरफ़ेस (यूआई) थ्रेड को जगाती है. इससे यह सिग्नल मिलता है कि नया फ़्रेम रेंडर करने का समय आ गया है.
  2. ऐप्लिकेशन, सीपीयू और जीपीयू संसाधनों का इस्तेमाल करके, यूज़र इंटरफ़ेस (यूआई) थ्रेड, RenderThread, और hwuiTasks में फ़्रेम रेंडर करता है. यूज़र इंटरफ़ेस (यूआई) के लिए ज़्यादातर कैपेसिटी का इस्तेमाल इसी में किया जाता है.
  3. ऐप्लिकेशन, रेंडर किए गए फ़्रेम को बाइंडर का इस्तेमाल करके SurfaceFlinger पर भेजता है. इसके बाद, SurfaceFlinger स्लीप मोड में चला जाता है.
  4. SurfaceFlinger में मौजूद दूसरी EventThread, कॉम्पोज़िशन और डिसप्ले आउटपुट को ट्रिगर करने के लिए SurfaceFlinger को जगाती है. अगर SurfaceFlinger को पता चलता है कि कोई काम नहीं है, तो वह फिर से स्लीप मोड में चला जाता है.
  5. SurfaceFlinger, हार्डवेयर कंपोज़र (HWC)/हार्डवेयर कंपोज़र 2 (HWC2) या GL का इस्तेमाल करके कंपोज़िशन को मैनेज करता है. HWC/HWC2 कॉम्पोज़िशन तेज़ और कम पावर वाला होता है. हालांकि, इसमें कुछ सीमाएं होती हैं, जो सिस्टम ऑन चिप (SoC) पर निर्भर करती हैं. आम तौर पर, इसमें 4 से 6 मिलीसेकंड लगते हैं. हालांकि, यह दूसरे चरण के साथ ओवरलैप हो सकता है, क्योंकि Android ऐप्लिकेशन हमेशा तीन बार बफ़र किए जाते हैं. (ऐप्लिकेशन हमेशा तीन बार बफ़र किए जाते हैं, लेकिन हो सकता है कि SurfaceFlinger में सिर्फ़ एक फ़्रेम इंतज़ार में हो. इससे यह डबल बफ़रिंग जैसा दिखता है.)
  6. SurfaceFlinger, वेंडर ड्राइवर की मदद से डिसप्ले के लिए फ़ाइनल आउटपुट भेजता है और फिर EventThread के फिर से चालू होने का इंतज़ार करते हुए, स्लीप मोड में चला जाता है.

चलिए, 15409 मिलीसेकंड से शुरू होने वाले फ़्रेम को देखते हैं:

EventThread के चलने के साथ सामान्य यूज़र इंटरफ़ेस (यूआई) पाइपलाइन
पहली इमेज. सामान्य यूज़र इंटरफ़ेस (यूआई) पाइपलाइन, EventThread चल रहा है

पहली इमेज में, सामान्य फ़्रेम के बीच में एक सामान्य फ़्रेम है. इसलिए, यह यूज़र इंटरफ़ेस (यूआई) पाइपलाइन के काम करने के तरीके को समझने के लिए एक अच्छा शुरुआती पॉइंट है. TouchLatency के लिए, यूज़र इंटरफ़ेस (यूआई) थ्रेड की लाइन में अलग-अलग समय पर अलग-अलग रंग शामिल होते हैं. बार से थ्रेड की अलग-अलग स्थितियों का पता चलता है:

  • ग्रे. स्लीपिंग मोड.
  • नीला. चलाया जा सकता है (यह चल सकता है, लेकिन शेड्यूलर ने इसे अभी तक चलाने के लिए नहीं चुना है).
  • हरा. चालू है (शेड्यूलर को लगता है कि यह चालू है).
  • लाल. बिना रुकावट वाली नींद (आम तौर पर, कर्नेल में लॉक होने पर नींद आती है). इससे I/O लोड का पता चल सकता है. परफ़ॉर्मेंस से जुड़ी समस्याओं को डीबग करने के लिए काफ़ी मददगार.
  • नारंगी. I/O लोड की वजह से, डिवाइस को स्लीप मोड में नहीं भेजा जा सकता.

बिना रुकावट के नींद मोड चालू होने की वजह देखने के लिए, sched_blocked_reason ट्रैसपॉइंट से उपलब्ध, लाल रंग के बिना रुकावट के नींद मोड वाली स्लाइस चुनें.

EventThread के चलने के दौरान, TouchLatency के लिए यूज़र इंटरफ़ेस (यूआई) थ्रेड को चलाया जा सकता है. डिवाइस को किस वजह से रिबूट किया गया, यह देखने के लिए नीले सेक्शन पर क्लिक करें.

TouchLatency के लिए यूज़र इंटरफ़ेस (यूआई) थ्रेड
दूसरी इमेज. TouchLatency के लिए यूज़र इंटरफ़ेस (यूआई) थ्रेड

दूसरे चित्र में दिखाया गया है कि TouchLatency यूज़र इंटरफ़ेस (यूआई) थ्रेड को tid 6843 ने जगाया था, जो EventThread से जुड़ा है. यूज़र इंटरफ़ेस (यूआई) थ्रेड चालू हो जाता है, एक फ़्रेम रेंडर करता है, और SurfaceFlinger के इस्तेमाल के लिए उसे सूची में जोड़ता है.

यूज़र इंटरफ़ेस (यूआई) थ्रेड चालू हो जाता है, एक फ़्रेम रेंडर करता है, और SurfaceFlinger के इस्तेमाल के लिए उसे सूची में जोड़ता है
तीसरा डायग्राम. यूज़र इंटरफ़ेस (यूआई) थ्रेड चालू हो जाता है, एक फ़्रेम रेंडर करता है, और उसे सूची में जोड़ता है, ताकि SurfaceFlinger उसे इस्तेमाल कर सके

अगर किसी ट्रेस में binder_driver टैग चालू है, तो उसमें शामिल सभी प्रोसेस की जानकारी देखने के लिए, कोई बाइंडर लेन-देन चुना जा सकता है.

चौथी इमेज. बाइंडर लेन-देन

चौथे चित्र में दिखाया गया है कि 15, 423.65 मिलीसेकंड पर,SurfaceFlinger में मौजूद Binder:6832_1, tid 9579 की वजह से रन किया जा सकता है. यह TouchLatency की RenderThread है. बाइंडर लेन-देन के दोनों तरफ़, queueBuffer भी देखा जा सकता है.

SurfaceFlinger की तरफ़ से queueBuffer के दौरान, TouchLatency से फ़्रेम की संख्या 1 से 2 हो जाती है.

बाकी फ़्रेम की संख्या 1 से 2 हो जाती है
पांचवीं इमेज. जिन फ़्रेम को मंज़ूरी मिलना बाकी है उनकी संख्या 1 से 2 हो जाती है

पांचवें फ़िगर में ट्रिपल बफ़रिंग की सुविधा दिखाई गई है. इसमें दो फ़्रेम रेंडर हो चुके हैं और ऐप्लिकेशन तीसरे फ़्रेम को रेंडर करने वाला है. ऐसा इसलिए होता है, क्योंकि हमने पहले से ही कुछ फ़्रेम छोड़ दिए हैं. इसलिए, ऐप्लिकेशन एक के बजाय दो फ़्रेम को सेव रखता है, ताकि आगे कोई फ़्रेम न छूटे.

इसके तुरंत बाद, SurfaceFlinger के मुख्य थ्रेड को दूसरी EventThread से जगाया जाता है, ताकि वह डिसप्ले पर पुराने फ़्रेम को दिखा सके:

SurfaceFlinger की मुख्य थ्रेड को दूसरी EventThread से जगाया जाता है
छठी इमेज. SurfaceFlinger के मुख्य थ्रेड को दूसरी EventThread ने जगाया है

SurfaceFlinger सबसे पहले, बफ़र में मौजूद पुराने कॉन्टेंट को लॉक करता है. इससे, बफ़र में मौजूद कॉन्टेंट की संख्या 2 से 1 हो जाती है.

SurfaceFlinger सबसे पहले, पहले से मौजूद बफ़र को प्रोसेस करता है
सातवीं इमेज. SurfaceFlinger सबसे पहले, पहले से मौजूद बफ़र पर काम करता है

बफ़र को लॉच करने के बाद, SurfaceFlinger कॉम्पोज़िशन सेट अप करता है और डिसप्ले पर आखिरी फ़्रेम सबमिट करता है. (इनमें से कुछ सेक्शन, mdss ट्रैसपॉइंट के हिस्से के तौर पर चालू होते हैं. इसलिए, हो सकता है कि वे आपके SoC में शामिल न हों.)

SurfaceFlinger, कॉम्पोज़िशन सेट अप करता है और फ़ाइनल फ़्रेम सबमिट करता है
आठवां डायग्राम. SurfaceFlinger, कॉम्पोज़िशन सेट अप करता है और आखिरी फ़्रेम सबमिट करता है

इसके बाद, mdss_fb0 सीपीयू 0 पर चालू हो जाता है. mdss_fb0, डिसप्ले में रेंडर किए गए फ़्रेम को आउटपुट करने के लिए, डिसप्ले पाइपलाइन का कर्नेल थ्रेड है. हम mdss_fb0 को ट्रैस में अपनी लाइन के तौर पर देख सकते हैं. इसे देखने के लिए, नीचे की ओर स्क्रोल करें.

mdss_fb0, सीपीयू 0 पर चालू होता है
नौवीं इमेज. mdss_fb0, सीपीयू 0 पर चालू होता है

mdss_fb0 जागता है, कुछ समय के लिए चलता है, फिर बिना रुकावट के नींद में चला जाता है और फिर से जागता है.

उदाहरण: काम न करने वाला फ़्रेम

इस उदाहरण में, Pixel/Pixel XL के फ़्रेम रेट में होने वाले उतार-चढ़ाव को डीबग करने के लिए इस्तेमाल किए गए systrace के बारे में बताया गया है. उदाहरण के साथ-साथ, ट्रैक की ज़िप फ़ाइल डाउनलोड करें. इसमें इस सेक्शन में बताए गए अन्य ट्रैक भी शामिल हैं. इसके बाद, फ़ाइल को अनज़िप करें और अपने ब्राउज़र में systrace_tutorial.html फ़ाइल खोलें.

systrace खोलने पर, आपको कुछ ऐसा दिखेगा:

Pixel XL पर TouchLatency की सुविधा चालू है और ज़्यादातर विकल्प चालू हैं
10वीं इमेज. Pixel XL पर चल रहा TouchLatency (mdss और kgsl ट्रेसपॉइंट के साथ-साथ ज़्यादातर विकल्प चालू हैं)

फ़्रेम मिस होने की समस्या का पता लगाने के लिए, SurfaceFlinger में जाकर, फ़्रेम मिस होने की जानकारी वाली लाइन देखें. FrameMissed, HWC2 की एक सुविधा है. इससे, वीडियो की क्वालिटी को बेहतर बनाने में मदद मिलती है. अगर कोई डिवाइस, HWC2 का इस्तेमाल नहीं करता है, तो हो सकता है कि दूसरे डिवाइसों के लिए systrace देखते समय, 'फ़्रेम छूटना' लाइन मौजूद न हो. दोनों ही मामलों में, फ़्रेम मिस होने की वजह यह है कि SurfaceFlinger के एक बहुत ही सामान्य रनटाइम में रुकावट आई. साथ ही, vsync के दौरान ऐप्लिकेशन (com.prefabulated.touchlatency) के लिए, बफ़र में मौजूद डेटा की संख्या में कोई बदलाव नहीं हुआ.

SurfaceFlinger के साथ FrameMissed का कोरिलेशन
11वां डायग्राम. SurfaceFlinger के साथ FrameMissed का कोरिलेशन

इमेज 11 में, 15598.29&nbps;एमएस पर फ़्रेम नहीं भेजे जाने की जानकारी दी गई है. SurfaceFlinger, vsync इंटरवल के दौरान कुछ समय के लिए चालू हुआ और फिर बिना कोई काम किए बंद हो गया. इसका मतलब है कि SurfaceFlinger ने यह तय किया कि डिसप्ले पर फिर से फ़्रेम भेजने की ज़रूरत नहीं है. क्यों?

इस फ़्रेम के लिए, पाइपलाइन कैसे बंद हुई, यह समझने के लिए सबसे पहले ऊपर दिए गए काम करने वाले फ़्रेम के उदाहरण की समीक्षा करें. इससे आपको यह जानने में मदद मिलेगी कि systrace में सामान्य यूज़र इंटरफ़ेस (यूआई) पाइपलाइन कैसी दिखती है. जब आप तैयार हों, तो उस फ़्रेम पर वापस जाएं जिसे आपने देखना छोड़ा था और पीछे की ओर बढ़ें. ध्यान दें कि SurfaceFlinger तुरंत चालू और बंद हो जाता है. TouchLatency से, बाकी बचे फ़्रेम की संख्या देखने पर, दो फ़्रेम दिखते हैं. इससे यह पता चलता है कि क्या हो रहा है.

SurfaceFlinger चालू हो जाता है और तुरंत बंद हो जाता है
12वीं इमेज. SurfaceFlinger चालू हो जाता है और तुरंत फिर से स्लीप मोड में चला जाता है

SurfaceFlinger में फ़्रेम होने की वजह से, यह ऐप्लिकेशन की समस्या नहीं है. इसके अलावा, SurfaceFlinger सही समय पर चालू हो रहा है. इसलिए, यह SurfaceFlinger से जुड़ी कोई समस्या नहीं है. अगर SurfaceFlinger और ऐप्लिकेशन, दोनों सामान्य दिखते हैं, तो हो सकता है कि ड्राइवर से जुड़ी कोई समस्या हो.

mdss और sync ट्रेसपॉइंट चालू होने की वजह से, हमें फ़ेंस के बारे में जानकारी मिल सकती है. फ़ेंस, डिसप्ले ड्राइवर और SurfaceFlinger के बीच शेयर किए जाते हैं. ये फ़्रेम को डिसप्ले पर सबमिट करने के समय को कंट्रोल करते हैं. ये फ़ेंस, mdss_fb0_retire में दिखते हैं. इससे पता चलता है कि कोई फ़्रेम डिसप्ले पर कब है. ये फ़ेंस, sync ट्रेस कैटगरी के हिस्से के तौर पर दिए जाते हैं. SurfaceFlinger में कौनसे फ़ेंस किसी खास इवेंट से जुड़े हैं, यह आपके एसओसी और ड्राइवर स्टैक पर निर्भर करता है. इसलिए, अपने एसओसी वेंडर के साथ मिलकर काम करें, ताकि आपको अपने ट्रेस में फ़ेंस कैटगरी का मतलब समझ आ सके.

mdss_fb0_retire fences
13वां डायग्राम. mdss_fb0_retire fences

इमेज 13 में एक फ़्रेम दिखाया गया है, जो उम्मीद के मुताबिक 16.7 मिलीसेकंड के बजाय 33 मिलीसेकंड के लिए दिखाया गया था. उस स्लाइस के आधे हिस्से में, उस फ़्रेम को नए फ़्रेम से बदल दिया जाना चाहिए था, लेकिन ऐसा नहीं हुआ. पिछला फ़्रेम देखें और उसमें कुछ भी खोजें.

बस्ड फ़्रेम से पहले का फ़्रेम
14वीं इमेज. बस्ट किए गए फ़्रेम से पहले का फ़्रेम

14वें फ़्रेम में, हर फ़्रेम के लिए 14.482 मिलीसेकंड का समय दिखाया गया है. दो फ़्रेम का ब्रोकन सेगमेंट 33.6 मि॰से॰ का था, जो कि दो फ़्रेम के लिए हमारी उम्मीद के मुताबिक है. हम 60 हर्ट्ज़ पर रेंडर करते हैं, यानी हर फ़्रेम के लिए 16.7 मि॰से॰. हालांकि, 14.482 मिलीसेकंड, 16.7 मिलीसेकंड के आस-पास नहीं है. इससे पता चलता है कि डिसप्ले पाइप में कोई गड़बड़ी है.

यह पता लगाने के लिए कि फ़ेंस को किस चीज़ से कंट्रोल किया जाता है, यह देखें कि फ़ेंस कहां खत्म होती है.

फ़ेंस के आखिरी हिस्से की जांच करना
15वीं इमेज. फ़ेंस के आखिरी हिस्से की जांच करना

वर्कक्वे में __vsync_retire_work_handler शामिल होता है, जो फ़ेंस में बदलाव होने पर चल रहा होता है. कर्नेल सोर्स को देखकर, यह पता चलता है कि यह डिसप्ले ड्राइवर का हिस्सा है. ऐसा लगता है कि यह डिसप्ले पाइपलाइन के लिए अहम पाथ पर है. इसलिए, इसे जल्द से जल्द चलाया जाना चाहिए. इसे 70 यूएस या उससे ज़्यादा समय तक चलाया जा सकता है (शेड्यूल करने में ज़्यादा देरी नहीं होती), लेकिन यह वर्कक्वे है और हो सकता है कि इसे सही तरीके से शेड्यूल न किया जाए.

पिछले फ़्रेम की जांच करके देखें कि उससे कोई फ़र्क़ पड़ा है या नहीं. कभी-कभी, समय के साथ जिटर बढ़ सकता है और आखिर में समयसीमा खत्म हो सकती है.

पिछला फ़्रेम
16वीं इमेज. पिछला फ़्रेम

kworker पर मौजूद, रन की जा सकने वाली लाइन नहीं दिख रही है, क्योंकि चुनने पर व्यूअर इसे सफ़ेद कर देता है. हालांकि, आंकड़ों से पता चलता है कि डिसप्ले पाइपलाइन के क्रिटिकल पाथ के हिस्से के लिए, शेड्यूलर में 2.3 एमएस की देरी खराब है. आगे बढ़ने से पहले, डिसप्ले पाइपलाइन के क्रिटिकल पाथ के इस हिस्से को, वर्कक्वे (जो SCHED_OTHER सीएफ़एस थ्रेड के तौर पर चलता है) से किसी खास SCHED_FIFO थ्रेड पर ले जाएं. इस फ़ंक्शन के लिए, टास्क पूरा होने में लगने वाले समय की ऐसी गारंटी ज़रूरी है जो वर्कक्वे को नहीं दी जा सकती और न ही दी जानी चाहिए.

क्या इस वजह से वीडियो में रुकावट आ रही है? इस बारे में कुछ कहना मुश्किल है. आम तौर पर, ट्रेस से समस्या के बारे में पता नहीं चलता. जैसे, कर्नेल लॉक कॉन्टेंट की वजह से डिसप्ले के लिए ज़रूरी थ्रेड के स्लीप मोड में जाने की समस्या. क्या इस वजह से फ़्रेम नहीं दिखे? बिल्कुल. फ़ेंस टाइम 16.7 मि॰से॰ होने चाहिए, लेकिन फ़्रेम छोड़ने से पहले के फ़्रेम में, ये टाइम बिलकुल भी आस-पास नहीं हैं. डिसप्ले पाइपलाइन कितनी ज़्यादा कसकर जुड़ी हुई है, यह देखते हुए यह मुमकिन है कि फ़ेंस टाइमिंग के आस-पास होने वाली गड़बड़ी की वजह से फ़्रेम गिर गया हो.

इस उदाहरण में, __vsync_retire_work_handler को वर्कक्वे से एक खास kthread में बदलने का समाधान शामिल था. इससे, गेम में होने वाली झटकों में काफ़ी सुधार हुआ है. साथ ही, गेम में बॉल के उछलने की जांच करने वाले टेस्ट में भी झटके कम हुए हैं. इसके बाद के ट्रैस से पता चलता है कि फ़ेंस टाइमिंग 16.7 मिलीसेकंड के आस-पास है.