1s से 10ms: API Gateway में Prometheus की देरी को कम करना
ZhengSong Tu
January 31, 2023
1 से 2 सेकंड की देरी वाले अनुरोध
APISIX समुदाय में, उपयोगकर्ताओं ने एक रहस्यमय घटना की सूचना दी है: जब ट्रैफ़िक अनुरोध सामान्य रूप से तैनात APISIX क्लस्टर में प्रवेश करते हैं, तो कुछ अनुरोधों में 1 से 2 सेकंड की असामान्य रूप से लंबी देरी होती है। उपयोगकर्ता का QPS स्केल लगभग 10,000 है, और इस प्रकार का असामान्य अनुरोध दुर्लभ है, जो हर कुछ मिनट में केवल 1 से 3 बार दिखाई देता है।
उपयोगकर्ताओं ने अपने उच्च-विलंबता वाले अनुरोधों के कैप्चर को इश्यूज़ में प्रदान किया। इन स्क्रीनशॉट्स से देखा जा सकता है कि वास्तव में उच्च विलंबता वाले अनुरोध हैं, कुछ तो सेकंड स्तर तक पहुंच सकते हैं।


इसके साथ एक और ध्यान देने योग्य घटना है: वर्कर प्रक्रिया में से एक का CPU उपयोग 100% तक पहुंच जाता है।

विकास टीम ने इस घटना के होने की शर्तों को जाना:
- Prometheus प्लगइन सक्षम है, और Prometheus Exporter APISIX एंडपॉइंट
/apisix/prometheus/metricsतक पहुंचकर मेट्रिक्स एकत्र करता है। - Prometheus प्लगइन द्वारा गिने जाने वाले मेट्रिक्स की संख्या एक निश्चित स्केल तक पहुंच जाती है, आमतौर पर दसियों हज़ार।
इस घटना को उद्योग में "लॉन्ग टेल अनुरोध" कहा जाता है। यह उस स्थिति को संदर्भित करता है जब अनुरोधों के एक छोटे प्रतिशत में अनुरोध समय असामान्य रूप से लंबा होता है जबकि अधिकांश अनुरोधों का प्रतिक्रिया समय सामान्य होता है। यह बैकएंड सिस्टम में प्रदर्शन बाधा, अपर्याप्त संसाधन, या अन्य कारणों से हो सकता है। यह एक घातक बग नहीं है, लेकिन यह अंतिम उपयोगकर्ता अनुभव को गंभीर रूप से प्रभावित करता है।
विस्तार से समझना
एक ओपन-सोर्स Lua लाइब्रेरी nginx-lua-prometheus के आधार पर, APISIX ने एक Prometheus प्लगइन विकसित किया है जो मेट्रिक्स को ट्रैक और एकत्र करने की कार्यक्षमता प्रदान करता है। जब Prometheus Exporter APISIX द्वारा एक्सपोज़ किए गए Prometheus संकेतकों के एंडपॉइंट तक पहुंचता है, तो APISIX nginx-lua-prometheus लाइब्रेरी द्वारा प्रदान की गई फ़ंक्शन को कॉल करेगा ताकि मेट्रिक्स के गणना परिणामों को एक्सपोज़ किया जा सके।
विकास टीम ने समस्या का पता लगाया: nginx-lua-prometheus में मेट्रिक्स संकेतकों को एक्सपोज़ करने के लिए उपयोग की जाने वाली फ़ंक्शन prometheus:metric_data()।
हालांकि, यह केवल एक प्रारंभिक अनुमान है, और यह साबित करने के लिए सीधे सबूत की आवश्यकता है कि लॉन्ग टेल अनुरोध इससे संबंधित हैं, और निम्नलिखित मुद्दों को स्पष्ट करने की आवश्यकता है:
- यह फ़ंक्शन वास्तव में क्या करता है?
- यह फ़ंक्शन लॉन्ग टेल अनुरोध क्यों पैदा करता है?
विकास टीम ने समस्या को पुन: उत्पन्न करने के लिए एक स्थानीय वातावरण का निर्माण किया, जो मुख्य रूप से निम्नलिखित परिदृश्यों का अनुकरण करता है:
- अनुकरण किए गए क्लाइंट द्वारा APISIX द्वारा अपस्ट्रीम को प्रॉक्सी किए गए सामान्य अनुरोध भेजे जाते हैं।
- Prometheus Exporter हर 5 सेकंड में
/apisix/prometheus/metricsपर जाता है, जिससे APISIXprometheus:metric_data()फ़ंक्शन को कॉल करता है।
पुन: उत्पन्न वातावरण:

टेस्ट करते समय, हमने wrk2 के टेस्ट परिणामों में P100 और अन्य संकेतकों का अवलोकन किया ताकि यह पुष्टि की जा सके कि लॉन्ग टेल अनुरोध की घटना है या नहीं। हमने APISIX का एक फ्लेम ग्राफ बनाया ताकि लॉन्ग टेल अनुरोध होने पर CPU उपयोग का अवलोकन किया जा सके।
wrk2 से टेस्ट परिणाम:
विलंबता वितरण (HdrHistogram - असंशोधित विलंबता (देरी से शुरू होने को ध्यान में नहीं रखा गया)) 50.000% 1.13ms 75.000% 2.56ms 90.000% 4.82ms 99.000% 14.70ms 99.900% 27.95ms 99.990% 74.75ms 99.999% 102.78ms 100.000% 102.78ms
इस टेस्ट परिणाम के अनुसार, यह निष्कर्ष निकाला जा सकता है कि टेस्ट के दौरान, 99% अनुरोध 14.70 मिलीसेकंड के भीतर पूरे हो गए, और कुछ अनुरोध 100 मिलीसेकंड से अधिक समय लेते हैं। और हमने मेट्रिक्स की संख्या को एक चर के रूप में उपयोग करके कई टेस्ट किए, और पाया कि मेट्रिक्स की संख्या P100 की देरी के साथ रैखिक रूप से बढ़ती है। यदि मेट्रिक्स 100,000 स्तर तक पहुंच जाते हैं, तो P100 सेकंड स्तर तक पहुंच जाएगा।
परिणामी फ्लेम ग्राफ:

फ्लेम ग्राफ के फ़ंक्शन स्टैक से देखा जा सकता है कि prometheus:metric_data() सबसे लंबी क्षैतिज चौड़ाई पर कब्जा करता है, जो बहुत अधिक CPU खपत को साबित करता है, और सीधे यह निर्धारित करता है कि prometheus:metric_data() लॉन्ग टेल अनुरोध पैदा करता है।
आइए संक्षेप में विश्लेषण करें कि prometheus:metric_data() फ़ंक्शन क्या करता है।
prometheus:metric_data() साझा मेमोरी से मेट्रिक्स प्राप्त करेगा, उन्हें वर्गीकृत करेगा, और उन्हें Prometheus-संगत टेक्स्ट प्रारूप में प्रोसेस करेगा। इस प्रक्रिया में, सभी मेट्रिक्स को शब्दकोशीय क्रम में क्रमबद्ध किया जाएगा, और मेट्रिक्स के उपसर्ग को रेगुलर एक्सप्रेशन के साथ प्रोसेस किया जाएगा। अनुभव के अनुसार, ये बहुत महंगे ऑपरेशन हैं।
एक अपूर्ण अनुकूलन प्रयास
एक बार जब हमने देरी का कारण बनने वाले कोड का पता लगा लिया, तो अगला कदम फ्लेम ग्राफ के साथ कोड का विस्तार से विश्लेषण करना और अनुकूलन के लिए जगह ढूंढना है।
फ्लेम ग्राफ से, हमने fix_histogram_bucket_labels फ़ंक्शन का पता लगाया। इस फ़ंक्शन की समीक्षा करने पर, हमें दो संवेदनशील फ़ंक्शन मिले: string:match और string:gusb। इन दोनों फ़ंक्शन को LuaJIT द्वारा JIT संकलित नहीं किया जा सकता है। वे केवल व्याख्या और निष्पादित किए जा सकते हैं।
LuaJIT Lua प्रोग्रामिंग भाषा के लिए एक JIT कंपाइलर है, जो Lua कोड को मशीन कोड में संकलित कर सकता है और इसे चला सकता है। यह Lua कोड को चलाने के लिए इंटरप्रेटर का उपयोग करने की तुलना में उच्च प्रदर्शन प्रदान कर सकता है।
LuaJIT का उपयोग करने का एक लाभ यह है कि यह कोड के निष्पादन की गति को बहुत बढ़ा सकता है। यह APISIX को बड़ी संख्या में अनुरोधों को संसाधित करते समय कम विलंबता बनाए रखने और उच्च-समवर्ती वातावरण में बेहतर प्रदर्शन करने की अनुमति देता है।
इसलिए, LuaJIT द्वारा संकलित नहीं किए जा सकने वाला कोड एक संभावित प्रदर्शन बाधा बन जाता है।
हमने उपरोक्त जानकारी को संकलित किया और इश्यू: लॉन्ग टेल अनुरोध घटना को अनुकूलित करें को nginx-lua-prometheus में सबमिट किया, जहां हम इस प्रोजेक्ट के लेखक Knyar से जुड़े और अनुकूलन के लिए जगह की खोज की। Knyar ने तुरंत प्रतिक्रिया दी, और हमने उन जगहों को स्पष्ट किया जिन्हें अनुकूलित किया जा सकता है। इसलिए एक PR सबमिट किया गया: चोर: प्रदर्शन में सुधार के लिए string match के बजाय ngx.re.match का उपयोग करें अनुकूलन के लिए।
इस PR में, हमने मुख्य रूप से निम्नलिखित पूरा किया:
string:matchके बजायngx.re.matchका उपयोग करेंstring:gusbकोngx.re.gsubसे बदलें
इस अनुकूलन को पूरा करने के बाद, हम जानते हैं कि यह जो प्रदर्शन सुधारता है वह सीमित है, यह समस्या को मूल रूप से हल नहीं कर सकता है। मूल समस्या यह है:
NGINX एक मल्टी-प्रोसेस सिंगल-थ्रेडेड आर्किटेक्चर है। सभी वर्कर प्रक्रियाएं TCP (ट्रांसमिशन कंट्रोल प्रोटोकॉल) कनेक्शन को मॉनिटर करेंगी, लेकिन एक बार कनेक्शन वर्कर प्रक्रिया में प्रवेश कर जाता है, तो इसे अन्य वर्कर प्रक्रियाओं में प्रोसेस करने के लिए माइग्रेट नहीं किया जा सकता है।
इसका मतलब है कि यदि एक वर्कर प्रक्रिया बहुत व्यस्त है, तो उस वर्कर प्रक्रिया के भीतर अन्य कनेक्शन समय पर प्रोसेस नहीं हो सकते हैं। दूसरी ओर, प्रक्रिया के भीतर सिंगल-थ्रेडेड मॉडल का मतलब है कि सभी CPU-गहन और IO-गहन कार्यों को क्रमिक रूप से किया जाना चाहिए। यदि एक कार्य को निष्पादित करने में लंबा समय लगता है, तो अन्य कार्यों को अनदेखा किया जा सकता है, जिसके परिणामस्वरूप कार्य प्रोसेसिंग समय में असमानता हो सकती है।
prometheus:metric_data() गणना के लिए CPU समय स्लाइस का एक बड़ा हिस्सा लेता है, जिससे सामान्य अनुरोधों को प्रोसेस करने के लिए CPU संसाधनों को निचोड़ा जाता है। यही कारण है कि आप एक वर्कर प्रक्रिया को 100% CPU उपयोग पर देखते हैं।
इस समस्या के आधार पर, हमने उपरोक्त अनुकूलन को पूरा करने के बाद विश्लेषण जारी रखा, और फ्लेम ग्राफ कैप्चर किया:

उपरोक्त फ्लेम ग्राफ builtin#100 luajit/lua लाइब्रेरी फ़ंक्शन (जैसे string.find) का प्रतिनिधित्व करता है, जिसे https://github.com/openresty/openresty-devel-utils/blob/master/ljff.lua में इस प्रोजेक्ट के माध्यम से एक्सेस किया जा सकता है ताकि संबंधित फ़ंक्शन नाम प्राप्त किया जा सके।
कैसे उपयोग करें:
$ luajit ljff.lua 100 FastFunc table.sort
चूंकि मेट्रिक्स की गणना में अत्यधिक CPU का उपयोग होता है, हम मेट्रिक्स की गणना करते समय CPU समय स्लाइस छोड़ने पर विचार करते हैं।
APISIX के लिए, सामान्य अनुरोधों को प्रोसेस करने की प्राथमिकता सबसे अधिक है, और CPU संसाधनों को इस ओर झुकाया जाना चाहिए। साथ ही, prometheus:metric_data() केवल Prometheus Exporter मेट्रिक्स प्राप्त करने की दक्षता को प्रभावित करेगा।
OpenResty दुनिया में, CPU समय स्लाइस छोड़ने का एक छिपा हुआ तरीका है: ngx.sleep(0)। हम इस विधि को prometheus:metric_data() में शामिल करते हैं। मेट्रिक्स को प्रोसेस करते समय, हम एक निश्चित संख्या में मेट्रिक्स (जैसे 200 मेट्रिक्स) को प्रोसेस करने के बाद CPU समय स्लाइस छोड़ देंगे ताकि नए आने वाले अनुरोधों को प्रोसेस करने का मौका मिल सके।
हमने इस अनुकूलन के लिए एक PR सबमिट किया: फीचर: प्रदर्शन अनुकूलन।