NYTProf के लिए लाइन-दर-लाइन आंकड़े कुल योग से मेल नहीं खाते हैं?

Question

मेरे पास एक पर्ल स्क्रिप्ट है जो चलाने में लगभग 30 मिनट लगती है, इसलिए निश्चित रूप से मैं डेवेल :: NYTProf चलाता हूं। महान प्रोफाइलर। मेरे कई subs के लिए, मुझे कुछ डेटा मिल रहा है जो मुझे समझ में नहीं आता है।

मैं डिफ़ॉल्ट NYTProf सेटिंग्स का उपयोग कर लिनक्स पर 5.10.0 के साथ चल रहा हूं।

एचटीएमएल आउटपुट में, प्रत्येक subs में एक सारांश अनुभाग है जिसमें कहा गया है कि उप और उसके बच्चों में कितना समय व्यतीत होता है और फिर मुझे लाइन जानकारी देने के लिए आगे बढ़ता है।

रेखा आंकड़े फ़ंक्शन में व्यतीत कुल में शामिल नहीं होते हैं। क्या देता है?

उदाहरण के लिए, मेरे पास एक फ़ंक्शन है जो 233s (57 + 166) का उपयोग करने की सूचना देता है। लाइन-बाय-लाइन नंबर रिपोर्ट में एक पंक्ति है जो 20s का उपयोग करती है, दूसरा जो 4 का उपयोग करता है और 2 का उपयोग करता है। अन्य पंक्तियां < 1s हैं और फ़ंक्शन इतना लंबा नहीं है।

इस विसंगति को हल करने के लिए मैं क्या कर सकता हूं?

मैं पर्ल 5.12 पर जा सकता हूं लेकिन निर्भरता स्थापित करने के लिए कुछ काम करेगा। मुझे इसे धीमे मोड में चलाने में खुशी है। नमूना आवृत्ति बढ़ाने के लिए कोई तरीका है? एक धीमी मशीन पर भागो?

नमूना के लिए यहां क्लिक करें: my NYTProf output। इस मामले में, उप को 225 सेकंड का उपयोग करने की सूचना दी जाती है, लेकिन सभी संख्याओं को जोड़कर 56 सेकंड उत्पन्न होते हैं। यह रन था अनुकूलन बंद:

setenv NYTPROF optimize=0:file=nytprof.optout 

अद्यतन मैं findcaller = 1 विकल्प ध्वज का उपयोग कर पर्ल 5.12 के साथ फिर से चलाएं गया है के रूप में अधिक या कम एक ही परिणाम के साथ का सुझाव दिया। (मैं एक अलग डेटासेट पर चला गया)

अद्यतन टिम बी सही है। मैंने अपने कुछ प्रमुख सबस को स्मोचिंग का उपयोग करने के बजाय खुद को कैशिंग करने के लिए बदल दिया है और NYTProf परिणाम फिर से उपयोगी हैं। धन्यवाद टिम।

Answer 1

मैं सिर्फ NYTProf प्रलेखन को यह जोड़ दिया है: एक बयान प्रोफाइलर है कि जब अनुरोध किया गया: अगर वक्तव्य और उपनेमका समय

NYTProf मेल नहीं खाते

= head2 दो प्रोफाइलर है पर्ल एक से दूसरे पर्ल बयान से चलता है, और एक सबरूटीन प्रोफाइलर कि लागू है जब पर्ल कॉल या एक सबरूटीन से रिटर्न।

एक सबरूटीन के लिए व्यक्तिगत बयान समय आमतौर पर सबरूटीन के लिए विशेष समय की तुलना में थोड़ा कम जोड़ें। ऐसा इसलिए है क्योंकि सबरूटीन कॉल और वापसी ओवरहेड्स की हैंडलिंग सबरूटीन के लिए विशेष समय में शामिल किया गया है है। अंतर केवल एक नया माइक्रोसेकंड हो सकता है लेकिन है कि सबरूटीन्स कि बार के हजारों की बुलाया सैकड़ों के लिए ध्यान देने योग्य हो सकता है।

कथन प्रोफाइलर ट्रैक करता है कि लेखन कथन प्रोफाइल डेटा डिस्क पर ओवरहेड पर कितना समय व्यतीत किया गया था। सबरूटीन प्रोफाइलर ओवरहेड्स है में प्रवेश करने और करने के क्रम में सबरूटीन छोड़ने एक और अधिक सटीक प्रोफ़ाइल दे के बीच जमा घटा देती है। कथन प्रोफाइलर आमतौर पर बहुत तेज होता है क्योंकि अधिकतर लिखने के लिए ज़िप संपीड़न के लिए बफर किया जाता है, इसलिए प्रोफाइलर ओवरहेड प्रति स्टेटमेंट बहुत छोटा होता है, अक्सर एक 'टिक' होता है। परिणाम यह है कि संचित ओवरहेड काफी शोर है। यह सबराउटिन के लिए अधिक महत्वपूर्ण हो जाता है कि को अक्सर बुलाया जाता है और तेज़ भी होता है। यह एक और, छोटे, विसंगति बयान समय और अनन्य बार के बीच करने के लिए योगदान हो सकता है।

शायद यह कथन समय कॉलम (31.7) के योग और subroutine (57.2s) के लिए विशेष समय के बीच अंतर बताता है। अंतर प्रति कॉल लगभग 100 माइक्रोसॉन्ड की मात्रा है (जो थोड़ा अधिक लगता है, लेकिन अनावश्यक रूप से ऐसा नहीं है)।

बयान प्रोफाइलर कितना समय खर्च पर खर्च किया गया था, डिस्क पर बयान प्रोफ़ाइल डेटा तैयार करने जैसा का ट्रैक रखता है। सबराउटिन प्रोफाइलर एक अधिक सटीक प्रोफ़ाइल देने के लिए सबराउटिन में प्रवेश करने और छोड़ने के बीच ओवरहेड्स में अंतर को घटा देता है।

कथन प्रोफाइलर आमतौर पर बहुत तेज़ होता है क्योंकि अधिकांश लिखने के लिए ज़िप संपीड़न के लिए buffered मिलता है, इसलिए प्रति कथन प्रोफाइलर ओवरहेड बहुत छोटा होता है, अक्सर एक 'टिक' होता है। नतीजा यह है कि संचित ओवरहेड काफी शोर है। यह उन सबराउटिन के लिए अधिक महत्वपूर्ण हो जाता है जिन्हें अक्सर कहा जाता है और तेज़ भी होते हैं (इस मामले में 250303 कॉल 89 9 6/कॉल पर)। इसलिए मुझे संदेह है कि यह कथन समय और विशेष समय के बीच विसंगति में एक और छोटा, योगदान है।

= head2 शीर्षक उपनेमका समय कहा जाता है Subs मेल नहीं खाते हैं

कुल मिलाकर सबरूटीन बार की तरह एक शीर्षक के साथ रिपोर्ट कर रहे हैं "खर्च:

इससे भी महत्वपूर्ण बात, मैं भी इस अनुभाग जोड़ दिया है 10s (2 + 8) भीतर ... "। इस उदाहरण में, सेकंड सबराउटिन ("समावेशी समय") के अंदर और के अंदर बिताए गए थे, में 8 सेकंड खर्च किए गए सबराउटिन इस द्वारा बुलाए गए थे। यही कारण है कि समय में खर्च सबरूटीन कोड में ही ( "अनन्य समय", कभी कभी भी "आत्म समय" कहा जाता है) के रूप में 2 सेकंड छोड़ देता है।

रिपोर्ट सबरूटीन के स्रोत कोड को दर्शाता है। उन कॉलों में बिताए गए समय के ब्योरे के साथ अन्य सबराउटिन पर पर कॉल करने वाली रेखाएं हैं।

कभी कभी सबरूटीन में कोड की लाइनों द्वारा किए गए कॉल के लिए समय की राशि समावेशी अनन्य समय में रिपोर्ट शीर्षक से भी कम है (10-2 उदाहरण में = 8 सेकंड ऊपर) ।

यहाँ क्या हो रहा है कहता है कि करने के लिए अन्य सबरूटीन्स किए जा रहे हैं लेकिन NYTProf बुला स्थान सही ढंग से निर्धारित करने के लिए इतना कॉल सही जगह पर रिपोर्ट में दिखाई नहीं देते में सक्षम नहीं है।

पर्ल के एक पुराने संस्करण का उपयोग करते हुए एक कारण (see below) है। दूसरा सबराउटिन को कॉल कर रहा है जो "गोटो & सब के माध्यम से बाहर निकलता है;" - मेमोइज़ मॉड्यूल का उपयोग करते हुए AUTOLOAD सबस और कोड में सबसे अधिक बार का सामना करना पड़ा।

सामान्य में समग्र सबरूटीन समय सही है और बयान या नेस्टेड सब कॉल समय की राशि से अधिक पर भरोसा होना चाहिए।

ज्ञापन मॉड्यूल प्राथमिक रूप से आपकी रिपोर्ट में विसंगति का कारण है। Memoize::__ANON__[...] पर कॉल ज्ञापन द्वारा उत्पन्न उप निष्पादित करें जो sub { unshift @_, $cref; goto &_memoizer; } जैसा दिखता है। उस goto &_memoizer को कॉलर को एक प्रकार की वापसी के रूप में लागू किया गया है, जिसके बाद निर्दिष्ट उप को कॉल किया गया है, और इसी तरह NYTProf इसे प्रोफाइल करता है।

भ्रम तथ्य यह है कि, हालांकि add_bit_to_map_memoizer तो कॉल में समय add_bit_to_map में जुड़ जाता है की फोन करने वाले के रूप में दर्ज किया जा रहा है, कॉल की फ़ाइल और लाइन नंबर स्थान के स्थान के रूप में दर्ज किया गया है के कारण होता है goto।

भविष्य में रिलीज में इसे सुधारना संभव हो सकता है।

मुझे इसकी जांच करने और दस्तावेज़ीकरण में सुधार करने के लिए धन्यवाद देने के लिए धन्यवाद।

टिम बन्स।

पेज। मैं mailing list पर NYTProf के बारे में प्रश्न पूछने की सलाह देता हूं।

Answer 2

perl के अनुकूलक को अक्षम करने का प्रयास करें। CPAN's Devel::NYTProf docs से:

अनुकूलन = 0

पर्ल अनुकूलक अक्षम करें।

डिफ़ॉल्ट रूप से NYTProf perl के अनुकूलक सक्षम करता है। इससे आपको समग्र प्रोफ़ाइल समय समग्र मिला है, लेकिन लाइनों के व्यक्तिगत सेट के लिए अजीब कथन की गणना कर सकता है। यह है क्योंकि पर्ल के पेफोल ऑप्टिमाइज़र ने प्रभावी रूप से कथनों को फिर से लिखा है लेकिन आप यह नहीं देख सकते कि पुन: लिखित संस्करण कैसा दिखता है।

उदाहरण के लिए:

1  if (...) { 
2   return; 
3  } may be rewritten as 

1 return if (...) 

इतना प्रोफ़ाइल एक बयान अपने स्रोत कोड में लाइन 2 के लिए गिनती क्योंकि वापसी पूर्ववर्ती लाइन पर अगर बयान में विलय हो गया नहीं दिखाया जाएगा।

अनुकूलन = 0 विकल्प का उपयोग अनुकूलक को निष्क्रिय ताकि आप कम समग्र प्रदर्शन, लेकिन अधिक सही रूप में सौंपा बयान मायने रखता है मिलेगा।

आप NYTProf उत्पादन पर अनुकूलक की प्रभाव के किसी भी अन्य उदाहरण (प्रदर्शन के अलावा अन्य, जाहिर है) मिल जाए तो कृपया हमें बताएं।