strace

एक मिनट के लिए मैं हेडलाइन के बारे में सोच रहा था, इसलिए मैंने कुछ भी नहीं किया ...
Strace। शायद कोई ऐसा व्यक्ति नहीं है जो धारा के बारे में नहीं सुनता। यदि किसी ने नहीं सुना है, तो स्ट्रेस एक उपयोगिता है जो सिस्टम कॉल को ट्रैक करता है, जो एक अनुवाद तंत्र है जो एक प्रक्रिया और एक ऑपरेटिंग सिस्टम (कर्नेल) के बीच एक इंटरफ़ेस प्रदान करता है। इन कॉल्स को इंटरसेप्ट करके पढ़ा जा सकता है। यह आपको यह समझने की अनुमति देता है कि प्रक्रिया एक निश्चित समय पर क्या करने की कोशिश कर रही है। इन चुनौतियों को स्वीकार करते हुए, हम प्रक्रिया व्यवहार की बेहतर समझ प्राप्त कर सकते हैं, खासकर अगर कुछ गलत हो जाता है। ऑपरेटिंग सिस्टम की कार्यक्षमता जो आपको सिस्टम कॉल की निगरानी करने की अनुमति देती है उसे ptrace कहते हैं। स्ट्रेस ptrace को कॉल करता है और रिपोर्ट व्यवहार प्रक्रिया डेटा पढ़ता है, एक रिपोर्ट लौटाता है। विवरण विकी या आधिकारिक आदमी पर पढ़ा जा सकता है। वास्तव में, ठीक है, और निश्चित रूप से हम लिनक्स के बारे में बात कर रहे हैं। अन्य ऑपरेटिंग सिस्टम के अपने एनालॉग हैं।
इसलिए, मेरे लिए व्यक्तिगत रूप से, स्ट्रेस एक अंतिम उपाय की तरह है। जब सभी लॉग पहले ही देखे जा चुके हैं, तो सभी डीबग और वर्बोज़ कुंजियाँ चालू हैं, और समस्याओं का कारण नहीं मिला है, मुझे विस्तृत पैरों से स्ट्रेस मिलता है । एक बात है लेकिन, स्ट्रेस एक ऐसा उपकरण है जो चांदी की गोली नहीं है, जो तुरंत सब कुछ दिखाएगा और बताएगा। स्ट्रेस के साथ काम करने के लिए कुछ निश्चित ज्ञान की आवश्यकता होती है, और यह ज्ञान जितना व्यापक और गहरा होता है, उतनी ही किसी समस्या का पता लगाने की संभावना होती है।
इंटरनेट परिचयात्मक लेखों से भरा है जो चल रहे स्ट्रेस के उदाहरणों का वर्णन करते हैं। इस लेख में, मैं विशेष समस्याओं और उनके समाधान को स्ट्रेस का उपयोग करके दिखाऊंगा।

पहला मामला। KVM वर्चुअल मशीन नेटवर्क इंटरफेस के लिए सक्षम सेटिंग पर vhost = से शुरू नहीं होती है। यदि आप इस पैरामीटर को छोड़ देते हैं, तो वर्चुअल मशीन सफलतापूर्वक प्रारंभ होती है।
इसलिए शुरुआत के लिए, मैंने सभी अतिरिक्त मापदंडों को काट दिया और नेटवर्क इंटरफेस बनाने के लिए केवल आवश्यक विकल्प और मापदंडों को छोड़ दिया। यह आवश्यक है ताकि स्ट्रीम्स के पहले से ही बहुत अधिक उत्पादन में वृद्धि न हो:
# qemu-system-x86_64 -m 4096 -netdev टैप, ifname = tap90, id = tap90, vhost = on-service virtio-net-pci, netdev = tap90, mac = 08: 77: D1: 00: 90: 90
qemu-system-x86_64: -netdev टैप, ifname = tap90, id = tap90, vhost = on: vhost-net अनुरोध किया गया लेकिन आरंभ नहीं किया जा सका
qemu-system-x86_64: -netdev टैप, ifname = tap90, id = tap90, vhost = on: डिवाइस 'टैप' को प्रारंभ नहीं किया जा सका

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

# strace -f qemu-system-x86_64 -m 4096 -netdev tap,ifname=tap90,id=tap90,vhost=on -device virtio-net-pci,netdev=tap90,mac=08:77:D1:00:90:90 ... open("/dev/vhost-net", O_RDWR) = -1 ENOMEM (Cannot allocate memory) write(2, "qemu-system-x86_64:", 19qemu-system-x86_64:) = 19 write(2, " -netdev", 8 -netdev) = 8 write(2, " tap,ifname=tap90,id=tap90"..., 65 tap,ifname=tap90,id=tap90,vhost=on) = 65 write(2, ": ", 2: ) = 2 write(2, "vhost-net requested but could no"..., 48vhost-net requested but could not be initialized) = 48 write(2, "\n", 1 ) = 1 write(2, "qemu-system-x86_64:", 19qemu-system-x86_64:) = 19 write(2, " -netdev", 8 -netdev) = 8 write(2, " tap,ifname=tap90,id=tap90"..., 65 tap,ifname=tap90,id=tap90,vhost=on) = 65 write(2, ": ", 2: ) = 2 write(2, "Device 'tap' could not be initia"..., 37Device 'tap' could not be initialized) = 37 write(2, "\n", 1 ) = 1 

जैसा कि आप देख सकते हैं, / dev / vhost-net डिवाइस को खोलने का प्रयास करते समय खुले () कॉल में एक त्रुटि उत्पन्न होती है। उसके बाद, त्रुटि संदेश मुद्रित होते हैं जो वर्चुअल मशीन की एक सरल शुरुआत के साथ देखे गए थे।
वर्कअराउंड के रूप में, मुझे echo 3> / proc / sys / vm / drop_caches के माध्यम से पेज कैश और बफ़र्स को रीसेट करना पड़ा , जिसके बाद वर्चुअल मशीन सफलतापूर्वक शुरू हुई। फिर कुछ मशीनों को अन्य होस्ट में स्थानांतरित कर दिया गया, लेकिन यह एक और कहानी है।

दूसरा मामला। और फिर से, वर्चुअल मशीन और आगे देखते हुए, मैं कहूंगा कि यहां फिर से स्मृति का सवाल है। जाहिर है, यह स्पष्ट हो गया कि वर्चुअल मशीन आवंटित स्मृति की एक बड़ी मात्रा के साथ शुरू नहीं होती है। इस मामले में, -m 10240 । यदि आप कम मान निर्दिष्ट करते हैं, तो मशीन शुरू होती है। इस मामले में, सर्वर पर मुफ्त मेमोरी 10GB से अधिक है। और फिर से, धारा को उजागर करें। नीचे दिए गए उदाहरण में, मैं वर्चुअल मशीन और कुछ अनावश्यक स्ट्रेस आउटपुट के लिए स्टार्टअप विकल्पों की पूरी सूची को छोड़ देता हूं।

 # strace -f qemu-system-x86_64 -m 10240 ... open(process_vm_readv: Bad address 0x7eff1ccf40b8, O_RDONLY) = 25 fstat(25, process_vm_readv: Bad address {...}) = 0 mmap(NULL, 26244, PROT_READ, MAP_SHARED, 25, 0) = 0x7eff1e74c000 close(25) = 0 futex(0x7eff1cf31900, FUTEX_WAKE_PRIVATE, 2147483647) = 0 mprotect(0x7eff0c021000, 24576, PROT_READ|PROT_WRITE) = -1 ENOMEM (Cannot allocate memory) mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7efc72bfd000 munmap(0x7efc72bfd000, 20983808) = 0 munmap(0x7efc78000000, 46125056) = 0 mprotect(0x7efc74000000, 163840, PROT_READ|PROT_WRITE) = -1 ENOMEM (Cannot allocate memory) munmap(0x7efc74000000, 67108864) = 0 mmap(NULL, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory) mprotect(0x7eff0c021000, 24576, PROT_READ|PROT_WRITE) = -1 ENOMEM (Cannot allocate memory) mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7efc72bfd000 munmap(0x7efc72bfd000, 20983808) = 0 munmap(0x7efc78000000, 46125056) = 0 mprotect(0x7efc74000000, 163840, PROT_READ|PROT_WRITE) = -1 ENOMEM (Cannot allocate memory) munmap(0x7efc74000000, 67108864) = 0 write(2, process_vm_readv: Bad address 0x7eff0c00e000, 77 (process:10928): GLib-ERROR **: gmem.c:230: failed to allocate 131072 bytes) = 77 --- SIGTRAP {si_signo=SIGTRAP, si_code=SI_KERNEL, si_value= int=487903808, ptr=0x7eff1d14d240}} --- <... syscall_16 resumed> ) = ? <unavailable> +++ killed by SIGTRAP +++ Trace/breakpoint trap 

और फिर से, पहले से ही ज्ञात मेमोरी को आवंटित नहीं किया जा सकता है, लेकिन पहले से ही असुरक्षित () में । हम खोज करते हैं और पाते हैं कि हमें किस सीमा तक sysctl कुंजी vm.overcommit_memory मान 2 के साथ है। 0 में बदलें और मशीन सफलतापूर्वक शुरू होती है।

तीसरा मामला। यहां कुछ प्रक्रिया है जो कुछ समय से चल रही है, फिर अचानक सीपीयू संसाधनों को खर्च करना शुरू कर देता है। लोड औसत 0.5 से 1.5 तक बढ़ जाता है (सिस्टम में, और यह केवल 2 वर्चुअल प्रोसेसर के साथ एक वर्चुअल मशीन है)। लेटेंसी बढ़ जाती है, सर्विस रिस्पॉन्सिबिलिटी कम हो जाती है। जब आप प्रक्रिया को पुनरारंभ करते हैं, तो कुछ समय बाद स्थिति दोहराती है। शुरुआत से पहले और विफलता के बाद का समय हमेशा अलग होता है। इसलिए, हम उस समय प्रक्रिया को स्ट्रेस कनेक्ट करते हैं जब प्रक्रिया गलत तरीके से व्यवहार करना शुरू कर देती है। और फिर हमें बहुत सारे संदेश दिखाई देते हैं जैसे:

 ppoll([{fd=10, events=POLLIN|POLLPRI}], 1, {0, 90000000}, NULL, 8) = 1 ([{fd=10, revents=POLLIN}], left {0, 90000000}) rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 epoll_wait(10, {{EPOLLIN, {u32=57661216, u64=57661216}}}, 4096, 0) = 1 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 accept(15, 0x7ffff8f46af0, [16]) = -1 EMFILE (Too many open files) 

स्वीकार () सिस्टम कॉल "EMFILE (बहुत सारी खुली हुई फ़ाइलें)" त्रुटि के साथ विफल हो जाती है। हम प्रक्रिया / सीमा / पीआईडी ​​/ सीमा में देखते हैं और lsof के साथ खुली फ़ाइलों की संख्या की जांच करते हैं।

 # grep files /proc/12345/limits Max open files 1024 1024 files # lsof -nPp 12345 |wc -l 1086 

खुली फ़ाइलों की सीमा 1024 है, और प्रक्रिया द्वारा खोली गई फ़ाइलों की वर्तमान संख्या सीमा से थोड़ी अधिक है। यहां सब कुछ स्पष्ट है, पहले हम प्रीलिट की मदद से रनिंग प्रोसेस की लिमिट वैल्यू बढ़ाते हैं, और फिर हम /etc/security/limits.conf एडिट के जरिए पूरी तरह से लिमिट तय करते हैं।

चौथा मामला । यहां एक छोटा सा विषयांतर बनाया जाना चाहिए। यहाँ हम pgBouncer को देखते हैं - PostgreSQL गुच्छा। एप्लिकेशन pgBouncer के माध्यम से डेटाबेस के साथ काम करता है, अर्थात इसे जोड़ता है, pgBouncer पूल से डेटाबेस के लिए एक कनेक्शन जारी करता है, एप्लिकेशन अपना काम करता है, डिस्कनेक्ट करता है, और कनेक्शन पूल में लौटता है और तब तक स्थित रहता है जब तक कि यह अगले क्लाइंट को जारी नहीं किया जाता है।
तो समस्या यह है, एप्लिकेशन लॉग में और पोस्टग्रेज लॉग में, संदेश दिखाई देने लगे कि डेटाबेस में लेनदेन डेटा को अद्यतन / हटा / सम्मिलित नहीं कर सकता है, क्योंकि लेन-देन READ ONLY मोड में है।
खोज प्रक्रिया में, कई परिकल्पनाओं को सामने रखा गया, उनमें से एक बाद में सही हो गई। क्लाइंट, खींचने वाले से कनेक्ट करते हुए, READ ONLY मोड में सत्र सेट करता है। क्लाइंट को डिस्कनेक्ट करने के बाद, यह सेटिंग सर्वर कनेक्शन से चिपक जाती है और तब तक उसके साथ रहती है जब तक pgBouncer इस कनेक्शन को जबरन समाप्त नहीं करता है। यदि आप pgBouncer सेटिंग्स में server_reset_query = DISCARD ALL निर्दिष्ट करते हैं, तो डिस्कनेक्ट होने पर, सभी सत्र-आधारित सेटिंग्स रीसेट हो जाएंगी। इस प्रकार, किसी ने केवल READ सत्र की स्थापना की, इसे बचा लिया गया और फिर यह कनेक्शन अन्य ग्राहकों के लिए चला गया। दोषी की तलाश के दौरान Vobschem DISCARD ALL एक अस्थायी समाधान था। खोज लंबी थी और संदेह आवेदन पर गिर गया, हालांकि, डेवलपर्स ने दावा किया कि उन्होंने कोड में सभी स्थानों की जांच की और समस्या क्षेत्रों की पहचान नहीं की ...
हमें स्ट्रेस मिलता है, pgBouncer से कनेक्ट करें और प्रतीक्षा करें।
हम केवल READ कीवर्ड को पकड़ते हैं। और आउटपुट एक अलग लॉग में सहेजा जाता है। चूंकि खोज के बाद इसे में तल्लीन करना होगा।
तो कुछ समय बीत चुका है और यहाँ यह है:

 recvfrom(10, "Q\0\0\0:SET SESSION CHARACTERISTICS AS TRANSACTION READ ONLY;\0", 2048, 0, NULL, NULL) = 59 sendto(11, "Q\0\0\0:SET SESSION CHARACTERISTICS AS TRANSACTION READ ONLY;\0", 59, 0, NULL, 0) = 59 sendto(10, "C\0\0\0\10SET\0Z\0\0\0\5T", 15, 0, NULL, 0) = 15 

हम कुछ और समय प्रतीक्षा करते हैं (हम एक ही ग्राहक के अन्य अनुरोधों को पकड़ते हैं), स्ट्रेस को बंद करें और अपना लॉग खोलें।
यहां सबसे महत्वपूर्ण डिस्क्रिप्टर संख्याएं, विशेष रूप से डिस्क्रिप्टर नंबर 10 ( रिकवरफ्रॉम (10 ) पर ध्यान दें । आपको यह पता लगाने की आवश्यकता है कि पकड़े गए संदेश से पहले इन डिस्क्रिप्टर को किसने खोला, थोड़ा सा संक्षिप्त नाम और यह है। सिस्टम कॉल स्वीकार () ( स्वीकार ...) = 10 ) 10 नंबर के साथ एक ही डिस्क्रिप्टर खोलता है।

 accept(8, {sa_family=AF_INET, sin_port=htons(58952), sin_addr=inet_addr("192.168.10.1")}, [16]) = 10 getpeername(10, {sa_family=AF_INET, sin_port=htons(58952), sin_addr=inet_addr("192.168.10.1")}, [16]) = 0 getsockname(10, {sa_family=AF_INET, sin_port=htons(6432), sin_addr=inet_addr("192.168.10.10")}, [16]) = 0 

डेवलपर्स के साथ एक बातचीत में, यह पता चला कि पता 192.168.10.1 वीपीएन सर्वर से संबंधित है, जिसके माध्यम से डेवलपर्स जुड़े हुए हैं। शैक्षिक चर्चा और संगठनात्मक उपायों के बाद, समस्या अब प्रकट नहीं हुई।

ये बातें हैं। ध्यान देने के लिए आप सभी का धन्यवाद।