कैसे रैखिक समय विंडोज में ओ (n²) में बदल जाता है

मैं हाल ही में अपने कार्य केंद्र पर बहु-मिनट की देरी में भाग गया। जांच के बाद, यह पता चला कि समस्या का कारण एक ताला था, जो पांच मिनट तक चल सकता था, जिसके दौरान ताला का स्रोत मूल रूप से नौ निर्देशों के चक्र में घूमता था।

मेरे लिए अपने पदों के लिए अच्छे शीर्षों का चयन करना बहुत महत्वपूर्ण है, लेकिन मुझे तुरंत याद आया कि एक महीने से भी कम समय पहले लिखी गई पोस्ट के अनुसार उपयुक्त नाम "48 कोर को नौ निर्देशों द्वारा अवरुद्ध किया गया था" पहले से ही [हैबे में अनुवाद किया गया था]। लॉक किए गए प्रोसेसर की संख्या अलग है, और चक्र थोड़ा लंबा है, लेकिन वास्तव में, यह सब देजा वू महसूस करता है। इसलिए, जब मैंने पाया नई समस्या की व्याख्या की, तो मैं इस बात पर विचार करना चाहता था कि ऐसा हर समय क्यों होता है ।

ऐसा क्यों हो रहा है?

मोटे तौर पर, इस तरह की समस्याएं एक अवलोकन के परिणामस्वरूप उत्पन्न होती हैं कि मैं कम्प्यूटिंग पर डॉसन के पहले कानून को कॉल करूंगा : ओ (एन ² ) एल्गोरिदम के लिए एक चुंबक है जो अच्छी तरह से पैमाने पर नहीं होता है : वे उत्पादन में आने के लिए पर्याप्त तेज़ हैं, लेकिन सब कुछ खराब करने के लिए पर्याप्त रूप से धीमा है। जब वे वहाँ पहुँचते हैं


ओ (एन ² ) कार्रवाई में - मेरे मामले से लिया गया डेटा

क्या चल रहा है? डेवलपर कोड लिखता है और O (n ² ) एल्गोरिदम का उपयोग करता है। शायद उसे यह एहसास नहीं है, या एल्गोरिथ्म बग के कारण ओ (एन ² ) बन जाता है, या डेवलपर को पता है कि वह ओ (एन ² ) है, लेकिन वह सोचता है कि यह कभी भी महत्वपूर्ण नहीं होगा। प्रयोगशाला स्थितियों में, कोड की गति स्वीकार्य है, और यह वास्तविक दुनिया में अधिकांश उपयोगकर्ताओं के लिए स्वीकार्य है, लेकिन फिर कोई व्यक्ति ऐप वेरिफायर के साथ 7,000 प्रक्रियाएं बनाता है या 180,000 सीएफजी तत्वों के साथ एक बाइनरी फ़ाइल बनाता है, या इतने बड़े डीएलएल को इकट्ठा करता है कि यह लगातार होता है एकल-लिंक्ड सूची स्कैन की गई है , जो पूरे प्रोसेसर को लेती है। वाल्व सोर्स 2 इंजन के लॉन्च समय पर काम करते समय, मुझे कई ओ (एन ² ) एल्गोरिदम मिले, जिनमें से प्रत्येक ने इंजन लॉन्च के समय में लगभग 30 सेकंड जोड़े, अर्थात, यह समस्या बहुत अलग डेवलपर्स के साथ होती है।

ओ (एन ² ) एल्गोरिदम के लिए एक चुंबक है जो अच्छी तरह से पैमाने पर नहीं होता है: वे उत्पादन में आने के लिए पर्याप्त तेज हैं, लेकिन जब वे वहां पहुंचते हैं तो सब कुछ खराब करने के लिए पर्याप्त धीमा होता है।

वास्तव में।

उदाहरण के लिए, ऐप वेरिफायर लॉग फ़ाइल नामों का निर्माण प्रत्येक चलने वाली प्रक्रिया के लिए रैखिक समय में किया जाता है , और यह सामान्य है जब तक आपको एहसास नहीं होता है कि यह O (n ² ) की ओर जाता है यदि कई प्रक्रियाएं चल रही हैं। कभी-कभी यह भी स्पष्ट नहीं होता है कि नेस्टेड लूप हैं, या औपचारिक रूप से यह ओ (एन ² ) नहीं है, या यह स्पष्ट नहीं है कि लूप इतने लंबे समय तक चल सकते हैं कि यह गति को प्रभावित कर सकता है ...

इसलिए इस अवसर पर विचार करें, कोड लिखते समय इसके बारे में सोचें, निगरानी करें कि भारी भार के तहत प्रदर्शन को कैसे बढ़ाया जाता है, और ऐसे भारी भार को कम करते समय कोड के संदिग्ध वर्गों की जांच करें। या इसे मेरे पास छोड़ दें ताकि मैं उन्हें खोज सकूं और अपने ब्लॉग पर लेख लिख सकूं।

आइए हमारी सामान्य शिकायतों पर वापस जाएं

हमेशा की तरह, मैंने अपने पुराने लेकिन अभी भी शक्तिशाली कार्य केंद्र के बारे में काम किया जिसमें 48 तार्किक प्रोसेसर और 96 जीबी रैम थे। मैंने क्रोम क्रोम बनाने के लिए निंजा क्रोम की शुरुआत की, लेकिन ... कुछ नहीं हुआ। मैंने देखा और बीस सेकंड इंतजार किया, लेकिन विधानसभा कभी भी शुरू नहीं हुई। इसलिए, मैंने बेशक, ETW ट्रेस रिकॉर्ड करने के लिए UIforETW पर स्विच किया। अधिक सटीक रूप से, मैंने इसे करने की कोशिश की। ट्रेस रिकॉर्डिंग शुरू करने की कोशिश कर रहा है, UIforETW जमा देता है । मेरे अभ्यास में पहली बार, एक बग ने सुरक्षात्मक उपायों का इस्तेमाल किया, ताकि मुझे इसकी खोज करने से रोका जा सके!

एक या दो मिनट के बाद, क्रोमियम की असेंबली शुरू हुई और UIforETW ने ट्रेस शुरू किया, लेकिन यह बहुत देर से शुरू हुआ और मुझे इसके बारे में थोड़ी भी जानकारी नहीं थी कि क्या हुआ।


चयनित सर्कुलर बफर ट्रेसिंग के साथ UIforETW विकल्प

जब कुछ दिन बाद ऐसा ही हुआ, तो UIforETW फिर से कुछ भी करने में असमर्थ था । इस बार, मैंने परिपत्र मेमोरी बफ़र्स में काम करने के लिए ट्रेस छोड़ दिया, इस तथ्य के लिए तैयार रहना कि तीसरी बार लटका हुआ होगा। हालांकि, इसने मेरे बिल्ड टूल्स की गति को बहुत कम कर दिया, इसलिए कुछ घंटों के बाद मैंने हार मान ली।

फिर इस स्थिति ने खुद को फिर से दोहराया। इस बार मैंने Microsoft - wprui द्वारा बनाए गए ETW ट्रेस लॉगिंग टूल को चलाया , और मैं रिकॉर्डिंग शुरू करने में सक्षम था। लगभग 40 सेकंड बाद, विधानसभा ने काम करना शुरू कर दिया और मुझे एक निशान मिला!

क्या मैं अब जांच शुरू कर सकता हूं?

इससे पहले, मैंने "टास्क मैनेजर" में देखा कि इन फ्रीज के दौरान WinMgmt.exe चल रहा था। WPA में CPU उपयोग (सटीक) डेटा को देखते हुए, मुझे यकीन था कि चालीस सेकंड से अधिक के दौरान, जिसके दौरान WinMgmt.exe लगभग एकमात्र कार्यशील प्रक्रिया थी, WinMgmt.exe बंद होने के बाद मेरी मशीन का जीवन आ गया:


WinMgmt.exe पूर्ण होने के बाद हम प्रक्रियाओं के जागरण का इंतजार करते हैं

यह सब बल्कि संदिग्ध है, लेकिन मेरे बुद्धिमान पाठकों को पता है कि "के बाद" का मतलब "कारण" नहीं है, और प्रमाण की आवश्यकता होगी।

पिछली बार की तरह, मैंने चार्ट पर अनलॉक करने के क्षण का अनुमान लगाया, स्विच-इन टाइम द्वारा संदर्भ स्विच को सॉर्ट किया और पिछले मान से लंबे समय के साथ पहले स्विच की तलाश की (उस समय की लंबाई को इंगित करता है जिसके दौरान थ्रेड निष्पादित नहीं किया गया था)। एक दर्जन धागे याद करने के बाद, जो थोड़े कम समय के लिए छूट गए, मुझे उनमें से पहला मिला जिसने 41.57 सेकंड इंतजार किया। स्लीपिंग थ्रेड WinMgmt.exe को नहीं जगाता है , लेकिन मुझे जल्दी से पता चला कि यह थ्रेड के साथ उठता है जो पहले WinMgmt.exe को एक मिलीसेकेंड का अंश जगाता है।

सीपीयू उपयोग (सटीक) रेखांकन और तैयार-धागा / नई-धागा अवधारणाओं की व्याख्या के लिए, इस ट्यूटोरियल या इस प्रलेखन को देखें ।

सामग्री स्विचिंग डेटा वाले स्क्रीनशॉट में, लाइन 17 में धारा 72,748 (WinMgmt.exe) है , जो धारा 74,156 (svchost.exe) को सक्रिय करती है । अगला, 19 रेखा पर, धागा 74,156 (svchost.exe) धागा 58,704 (svchost.exe) को सक्रिय करता है, जो 41.57 सेकंड के लिए इंतजार कर रहा था। यह पहला धागा है जो एक लंबी नींद के बाद उठता है और इससे प्रवाह की सक्रियता की श्रृंखला जारी रहती है। थ्रेड्स जो अभी सक्रिय किए गए हैं, उन्हें नए थ्रेड आईडी कॉलम में देखा जा सकता है, और फिर कुछ पंक्तियों को नीचे जा कर रीडिंग थ्रेड आईडी कॉलम में देखा जा सकता है, जिससे एक और थ्रेड सक्रिय होता है। नाम और प्रक्रिया आईडी आपको संदर्भ को समझने में मदद करते हैं। लाइन 17 लाइनों 18 और 19 के साथ जुड़ा हुआ है, लाइन 19 20 के साथ जुड़ा हुआ है, जो लाइन 23 के साथ जुड़ा हुआ है, जो लाइन 27 के साथ जुड़ा हुआ है, और इसी तरह; प्रत्येक धागा श्रृंखला में पिछले धागे से सक्रिय होता है:


राक्षस जागता है - लंबे समय तक निष्क्रिय धागे जीवन में आते हैं

41.57 एक धागा को अवरुद्ध करने के लिए एक लंबा समय है, लेकिन वास्तव में सैकड़ों धागे अवरुद्ध थे, और वे बहुत लंबे समय तक अवरुद्ध थे। अंतिम समय के बाद से उनके समय का एकमात्र कारण लगभग 41.5 सेकंड है क्योंकि हैंग हल होने से पहले ट्रेस की लंबाई।

ऐसा लगता है कि परिणाम इस सिद्धांत के अनुरूप हैं कि समस्या WinMgmt.exe में है , लेकिन वे इसे साबित नहीं करते हैं। जब मैंने ट्रेस-> सिस्टम कॉन्फ़िगरेशन-> सेवाओं में svchost.exe (3024) को देखा तो मेरा आत्मविश्वास बढ़ गया और पता चला कि यह एक Winmgmt सेवा है, लेकिन मुझे अभी भी अधिक निश्चितता की आवश्यकता थी।

थोड़ी अधिक अफवाह (समय में आगे और पीछे भटकना) होने के बाद, मैंने तय किया कि बातचीत का विस्तार से विश्लेषण करने के लिए बहुत जटिल हैं, खासकर बिना स्ट्रीम नामों के जो हमें संकेत दे सकते हैं कि svchost.exe (3024) में 25 अलग-अलग धागे क्या कर रहे हैं।

सबूत!

तब मैंने WinMgmt.exe दोषी सबूत को अलग तरीके से देखने का फैसला किया। शायद यह इसके साथ शुरू करने लायक था, लेकिन यह बहुत सरल होगा। मैंने WPA में प्रॉसेस टेबल से कमांड लाइन WinMgmt.exe ले ली और इसे मैन्युअल रूप से शुरू किया। कमांड का रूप है:

winmgmt.exe / Verrepository

और इसे पूरा करने में लगभग पांच मिनट लगे। जब यह काम किया (और मेरे पास बहुत समय था), मुझे पता चला कि मैं UIforETW से ETW ट्रेस शुरू नहीं कर सकता। इस तरह के सबूत किसी भी जटिल विश्लेषण से बेहतर थे जो मैं कर सकता था।


केवल लंबे समय से निष्क्रिय धागे प्रदर्शित करने के लिए कॉन्फ़िगरेशन

फिर मैंने पहले से चल रहे ट्रेस के साथ फिर से रिप्रो चलाया; ट्रेस का विश्लेषण करने के बाद, मैंने सौ से अधिक प्रक्रियाओं की खोज की जिनके धागे पांच मिनट से अधिक समय तक अवरुद्ध थे !

और फिर से बात ...

आदत से बाहर, मैंने सीपीयू उपयोग (नमूना) डेटा पर फिर से देखा कि क्या WinMgmt.exe समय बर्बाद कर रहा था। मुझे जल्दी से पता चला कि 96.5% नमूने repdrvfs.dll में थे ! CPageCache :: Read () , चार अलग-अलग स्टाकों पर कॉल किया गया:


चार रास्‍ते जो मुझे CPageCache की ओर ले गए: :: पढ़ें

इस फ़ंक्शन के लिए पूर्ण ढेर का एक पेड़ यहां दिखाया गया है, मुख्य रूप से उन Microsoft के लोगों के लिए जो इस समस्या पर शोध करना चाहते हैं:


CPageCache के लिए अग्रणी पूर्ण स्टैक :: तीन तरीकों से पढ़ें

मैंने एक पता स्तंभ जोड़ा और पाया कि 95.3% नमूने नौ निर्देशों के एक चक्र में थे (नमूने हमेशा नौ निर्देशों में से केवल सात में गिर गए (यदि आप जानना चाहते हैं कि क्यों, यहां देखें), लेकिन डीबगर ने चक्र का पूरा आकार दिखाया :


पते के नमूने - सात बहुत "गर्म" पते

फिर मैंने मैन्युअल रूप से winmgmt.exe / Verrepository शुरू किया, और उसी समय मैंने शाखा निर्देशों के बारे में सीपीयू काउंटर डेटा एकत्र किया जो निष्पादित हो रहे थे । इससे, मैं मोटे तौर पर पता लगा सकता था कि लूप कितनी बार चला। यह शायद आवश्यक नहीं था, लेकिन मैं यह सुनिश्चित करना चाहता था कि लूप को कई बार निष्पादित किया गया था, और धीरे-धीरे निष्पादित नहीं किया गया था (किसी कारण से)। मुझे लगा कि यह बहुत अच्छा था कि मैं इसे बस कर सकता हूं, बस बैच फ़ाइल में थोड़ा बदलाव करें। मुझे पता चला कि WinMgmt.exe ने प्रति चक्र लगभग एक शाखापूर्ण अनुदेश को क्रियान्वित किया, अर्थात, चक्र (जो, जैसा कि मैं पहले से ही जानता था, सीपीयू के अधिकांश समय का उपभोग करता है) बेहद तेज था, और मंदी इस तथ्य के कारण थी कि यह लाखों लोगों के बीच चला। समय।

Xperf देरी

सिर्फ सावधानी के लिए, मैंने यह देखने का निर्णय लिया कि इस घटना के दौरान UIforETW ट्रेसिंग क्यों नहीं शुरू कर सकता है। यह पता चला कि UIforETW xperf चल रहा था , लेकिन xperf इस कॉल स्टैक में 41.5 सेकंड (वास्तव में लंबा) के लिए निष्क्रिय था :

xperf.exe! wmain
xperf.exe! CStopTrace :: निष्पादित करें
perfctrl.dll! LoggingSession :: EnumLoggers
perfctrl.dll! लॉगिंगसैशन :: LoggingSession
perfctrl.dll! LoggingSession :: CreateProviderList
perfctrl.dll! GetProviderInfoCache
perfctrl.dll! CProviderInfoCache :: CProviderInfoCache
tdh.dll! TdhfEnumerateProviders
tdh.dll! TdhpWbemConnect
wbemprox.dll! CLocator :: ConnectServer
wbemprox.dll! CDCOMTrans :: DoActualConnection

संक्षेप में, xperf को Wbem द्वारा कहा जाता है, और इसलिए इस समस्या से अवरुद्ध है। xperf इसे शुरू करने से पहले ट्रेस को रोकने की कोशिश करता है, क्योंकि मैंने ट्रेस की शुरुआत को अधिक दोष सहिष्णु बनाने के लिए इस व्यवहार को जोड़ा। मुझे संदेह है कि अभी भी एक फांसी होगी, लेकिन मुझे यकीन नहीं है।

हम कम्प्यूटेशनल जटिलता के ग्राफ बनाते हैं

मैंने देखा कि WinMgmt.exe ने c: \ windows \ System32 \ wbem \ Repository निर्देशिका को स्कैन किया है, जो मेरी मशीन पर 1.9 GB है, इसलिए मैंने काम पर और ट्विटर पर यह बताने के लिए कहा कि यह निर्देशिका डेटा बिंदुओं को प्राप्त करने में कितना लेती है। मैंने लोगों को winmgmt.exe / Verrepository का रनटाइम ठीक करने के लिए भी कहा और शेड्यूल करना शुरू किया। भले ही ये परीक्षण पूरी तरह से अलग-अलग मशीनों पर अलग-अलग सीपीयू स्पीड के साथ किए गए हों, लेकिन ग्राफ काफी हद तक स्पष्ट था।


समय के वर्गमूल और रिपॉजिटरी के आकार के बीच संबंध

रिपॉजिटरी के आकार के लिए sqrt (समय) के अनुपात का यह ग्राफ छह विभिन्न मशीनों से प्राप्त डेटा के लिए अविश्वसनीय रूप से आदर्श है, और फिर भी, यह वास्तविक है। जाहिर है, VerifyRepository फ़ंक्शन का O (n ² ) प्रदर्शन है। यदि n GB में रिपॉजिटरी डायरेक्टरी का आकार है, तो VerifyRepository को लगभग 1.6 * n ² मिनट लगते हैं। यह सभी मूल्यों के लिए एक अच्छा मोटा अनुमान है - दूसरे विभाजन से दस मिनट तक।

महत्व

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

सौभाग्य से, मैंने पहले ही अपने आईटी विभाग के साथ काम करना शुरू कर दिया है। मुझे स्क्रिप्ट मिली जिसने WinMgmt लॉन्च किया और पता चला कि यह प्रति घंटा चलती है। इसका मतलब यह था कि मेरी मशीन 10% समय WinMgmt.exe / Verrepository चल रही थी, और मेरे कुछ सहयोगियों के पास 16% से अधिक समय था। विधानसभा से पहले दस मिनट की देरी होने की काफी अधिक संभावना है।

जब तक रिपोर्टें आने लगीं, तब तक उत्पादन के रास्ते ठीक हो चुके थे। स्क्रिप्ट वैकल्पिक थी, और निश्चित रूप से इसके कारण होने वाली समस्याओं के लायक नहीं थी, इसलिए इसका कॉल बंद करना ठीक था।

परिणाम

winmgmt.exe / Verrepository में नौ निर्देशों का एक चक्र होता है, जिसके निष्पादन की पुनरावृत्तियों की संख्या wbem रिपॉजिटरी के आकार के वर्ग के समानुपाती होती है । इस वजह से, कमांड का निष्पादन दस मिनट तक हो सकता है, हालांकि वास्तव में इसे कुछ ही सेकंड में निष्पादित किया जाना चाहिए। यह अपने आप में बुरा है।

लेकिन इससे भी बदतर, टीम अपने ऑपरेशन के दौरान एक WMI ( विंडोज मैनेजमेंट इंस्ट्रूमेंटेशन ) लॉक करती है, इसलिए WMI ऑपरेशन करने वाली कोई भी प्रक्रिया फ्रीज हो जाएगी।

अद्भुत पहेलियों

हर घंटे winmgmt.exe / Verrepository चलाने वाली स्क्रिप्ट ने कई वर्षों तक ऐसा किया, लेकिन समस्यात्मक व्यवहार केवल एक से दो महीने पहले दिखाई देने लगा। संभवतः, इसका मतलब है कि wbem रिपॉजिटरी हाल ही में बहुत बड़ी हो गई है। 0.5 जीबी की देरी को आसानी से अनदेखा कर दिया जाता है, लेकिन 1.0 जीबी और ऊपर से वे पहले से ही तनाव कर सकते हैं। जैसा कि ट्विटर पर सुझाया गया है, मैंने ऑब्जेक्ट्स.डेटा फ़ाइल के लिए strings.exe चला दिया । सबसे आम तार में से कई के नाम में polmkr होते हैं, लेकिन मुझे नहीं पता कि इसका क्या मतलब है।

मैंने ट्विटर पर एक बग रिपोर्ट प्रकाशित की , और सबसे पहले इसने डब्ल्यूएमआई टीम से कुछ आंदोलन का कारण बना, लेकिन फिर मुझे जवाब मिलना बंद हो गया, इसलिए मुझे नहीं पता कि अब क्या स्थिति है।

मैं प्रदर्शन समस्या के लिए एक फिक्स देखना चाहूंगा, और मैं चाहूंगा कि हमारा आईटी विभाग उस समस्या को खोजने और ठीक करने में सक्षम हो जो हमारे wbem रिपॉजिटरी को इतना बड़ा बनाता है। लेकिन अभी के लिए, आईटी विभाग ने हर घंटे अधिक / Verrepospository कमांड नहीं चलाने का वादा किया है, जिससे हमें सबसे खराब लक्षणों से बचने में मदद करनी चाहिए।

संदर्भ

• ETW ट्यूटोरियल, जांच और प्रलेखन की एक सामान्य सूची यहां उपलब्ध है: https://tinyurl.com/etwcentral
• सीपीयू उपयोग (नमूना) ट्यूटोरियल (यह जानने के लिए कि सीपीयू समय क्या खर्च होता है) यहां है , और प्रलेखन यहां है।
• CPU उपयोग (सटीक) ट्यूटोरियल (थ्रेड नहीं चला पाने के कारणों को खोजने के लिए) यहाँ है , और प्रलेखन यहाँ है।
• व्यक्तिगत लेख के लिंक पोस्ट के शरीर में दिए गए हैं, आप उन्हें मेरी श्रेणी की जांच रिपोर्टिंग में भी पा सकते हैं
• O (n ² ) एल्गोरिदम के बारे में अन्य कहानियाँ दुर्घटनावश द्विघात पर पढ़ी जा सकती हैं

रेडिट पर लेख की एक चर्चा यहाँ हैकर खबर पर एक चर्चा है , ट्विटर पर एक धागा यहाँ है, और संभवतः यहाँ है