من 1 ثانية إلى 10 مللي ثانية: تقليل تأخير Prometheus في بوابة API

طلبات بتأخيرات تتراوح بين 1 إلى 2 ثانية

في مجتمع APISIX، أبلغ المستخدمون عن ظاهرة غامضة: عندما تدخل طلبات المرور إلى مجموعة APISIX الموزعة بشكل طبيعي، يكون لدى عدد قليل من الطلبات تأخيرًا طويلًا بشكل استثنائي يتراوح بين 1 إلى 2 ثانية. مقياس QPS للمستخدم يبلغ حوالي 10,000، وهذا النوع من الطلبات غير الطبيعية نادر، حيث يظهر فقط 1 إلى 3 مرات كل بضع دقائق.

قدم المستخدمون لقطاتهم للطلبات ذات التأخير العالي في القضايا. يمكن أن نرى من هذه اللقطات أن هناك بالفعل طلبات ذات تأخير عالي، بعضها يمكن أن يصل إلى مستوى الثانية.

ظاهرة أخرى ملحوظة ترافق هذا: استخدام وحدة المعالجة المركزية (CPU) لإحدى عمليات العامل تصل إلى 100%.

تعلم فريق التطوير الشروط لحدوث هذه الظاهرة:

1. تم تمكين إضافة Prometheus، ولدى Prometheus Exporter الوصول إلى نقطة النهاية /apisix/prometheus/metrics في APISIX لجمع المقاييس.
2. عدد المقاييس التي تعدها إضافة Prometheus يصل إلى حجم معين، عادة عشرات الآلاف.

تُسمى هذه الظاهرة في الصناعة "طلبات الذيل الطويل". تشير إلى الحالة التي يكون فيها نسبة صغيرة من الطلبات لديها وقت طلب طويل بشكل غير طبيعي بينما معظم الطلبات لديها وقت استجابة طبيعي في مجموعة طلبات. يمكن أن يكون ذلك بسبب اختناق أداء في النظام الخلفي، أو نقص في الموارد، أو أسباب أخرى. إنه ليس خطأً قاتلًا، ولكنه يؤثر بشكل خطير على تجربة المستخدم النهائي.

تفصيل المشكلة

بناءً على مكتبة Lua مفتوحة المصدر nginx-lua-prometheus، طورت APISIX إضافة Prometheus التي توفر وظيفة تتبع وجمع المقاييس. عندما يصل Prometheus Exporter إلى نقطة النهاية للمؤشرات التي تعرضها APISIX، ستقوم APISIX باستدعاء الوظيفة التي توفرها مكتبة nginx-lua-prometheus لعرض نتائج حساب المقاييس.

حدد فريق التطوير المشكلة: الوظيفة prometheus:metric_data() المستخدمة لعرض مؤشرات المقاييس في nginx-lua-prometheus.

ومع ذلك، هذا مجرد استنتاج أولي، وهناك حاجة إلى أدلة مباشرة لإثبات أن طلبات الذيل الطويل مرتبطة بهذا، وهناك حاجة لتوضيح القضايا التالية:

1. ماذا تفعل هذه الوظيفة بالضبط؟
2. لماذا تسبب هذه الوظيفة طلبات الذيل الطويل؟

قام فريق التطوير ببناء بيئة محلية لإعادة إنتاج المشكلة، والتي تحاكي بشكل رئيسي السيناريوهات التالية:

1. محاكاة العميل الذي يرسل طلبًا عاديًا يتم توجيهه إلى الخادم الخلفي بواسطة APISIX.
2. محاكاة وصول Prometheus Exporter إلى /apisix/prometheus/metrics كل 5 ثوانٍ، مما يؤدي إلى استدعاء APISIX لوظيفة prometheus:metric_data().

بيئة إعادة الإنتاج:

عند إجراء الاختبار، لاحظنا P100 ومؤشرات أخرى في نتائج اختبار wrk2 لتأكيد وجود ظاهرة طلبات الذيل الطويل. قمنا بإنشاء رسم بياني للهب لـ APISIX لمراقبة استخدام وحدة المعالجة المركزية عند حدوث طلب ذيل طويل.

نتائج الاختبار من 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() تحتل أطول عرض أفقي، مما يثبت استهلاكًا كبيرًا لوحدة المعالجة المركزية، ويحدد بشكل مباشر أن prometheus:metric_data() تسبب طلبات الذيل الطويل.

دعونا نحلل باختصار ما تفعله وظيفة prometheus:metric_data().

تقوم prometheus:metric_data() بجلب المقاييس من الذاكرة المشتركة، وتصنيفها، ومعالجتها إلى تنسيق نصي متوافق مع Prometheus. في هذه العملية، يتم فرز جميع المقاييس بترتيب معجمي، ويتم معالجة بادئة المقاييس باستخدام تعبيرات عادية. كقاعدة عامة، هذه عمليات مكلفة للغاية.

محاولة تحسين غير مثالية

بمجرد تحديد الكود الذي تسبب في التأخير، تكون الخطوة التالية هي الجمع بين الرسم البياني للهب لتحليل الكود بالتفصيل وإيجاد مجال للتحسين.

من الرسم البياني للهب، حددنا وظيفة fix_histogram_bucket_labels. عند مراجعة هذه الوظيفة، وجدنا وظيفتين حساستين: string:match و string:gusb. لا يمكن لأي من هاتين الوظيفتين أن يتم تجميعهما بواسطة LuaJIT. يمكن فقط تفسيرهما وتنفيذهما.

LuaJIT هو مترجم JIT للغة البرمجة Lua، والذي يمكنه تجميع كود Lua إلى كود آلة وتشغيله. يمكن أن يوفر هذا أداءً أعلى من استخدام مترجم لتشغيل كود Lua.

أحد مزايا استخدام LuaJIT لتشغيل كود Lua هو أنه يمكن أن يزيد بشكل كبير من سرعة تنفيذ الكود. هذا يسمح لـ APISIX بالحفاظ على تأخير منخفض عند معالجة عدد كبير من الطلبات، وأداء أفضل في بيئة عالية التزامن.

لذلك، الكود الذي لا يمكن لـ LuaJIT تجميعه سيصبح عنق زجاجة أداء محتمل.

قمنا بتجميع المعلومات أعلاه وقدمنا قضية: تحسين ظاهرة طلبات الذيل الطويل إلى nginx-lua-prometheus، حيث تواصلنا مع المؤلف Knyar لهذا المشروع واستكشفنا المجال الذي يمكن تحسينه. رد Knyar بسرعة، ووضحنا الأماكن التي يمكن تحسينها. لذلك تم تقديم PR: chore: use ngx.re.match instead of string match to improve performance للتحسين.

في هذا PR، قمنا بشكل رئيسي بإكمال:

• استخدام ngx.re.match بدلاً من string:match
• استبدال string:gusb بـ ngx.re.gsub

بعد إكمال هذا التحسين، نعلم أن الأداء الذي يحسنه محدود، ولا يمكنه حل المشكلة بشكل جذري. المشكلة الجذرية هي:

NGINX هو بنية متعددة العمليات ووحيدة الخيط. جميع عمليات العامل ستقوم بمراقبة اتصالات TCP (بروتوكول التحكم في الإرسال)، ولكن بمجرد دخول اتصال إلى عملية عامل، لا يمكن نقله إلى عمليات عامل أخرى للمعالجة.

هذا يعني أنه إذا كانت عملية عامل مشغولة للغاية، فقد لا تتم معالجة الاتصالات الأخرى داخل تلك العملية في الوقت المناسب. من ناحية أخرى، فإن النموذج وحيد الخيط داخل العملية يعني أن جميع المهام المكثفة لوحدة المعالجة المركزية والمكثفة للإدخال/الإخراج يجب أن تتم بشكل تسلسلي. إذا استغرقت مهمة وقتًا طويلاً للتنفيذ، فقد يتم تجاهل المهام الأخرى، مما يؤدي إلى أوقات معالجة غير متساوية للمهام.

تقوم prometheus:metric_data() باحتلال جزء كبير من شرائح وقت وحدة المعالجة المركزية للحساب، مما يضغط على موارد وحدة المعالجة المركزية لمعالجة الطلبات العادية. هذا هو السبب في أنك ترى عملية عامل بنسبة 100% من استخدام وحدة المعالجة المركزية.

بناءً على هذه المشكلة، واصلنا التحليل بعد إكمال التحسين أعلاه، وقمنا بالتقاط الرسم البياني للهب:

الرسم البياني للهب أعلاه builtin#100 يمثل وظائف مكتبة luajit/lua (مثل string.find)، والتي يمكن الوصول إليها عبر https://github.com/openresty/openresty-devel-utils/blob/master/ljff.lua في هذا المشروع للحصول على اسم الوظيفة المقابلة.

كيفية الاستخدام:

$ luajit ljff.lua 100
FastFunc table.sort

نظرًا لأن حساب المقاييس يستغرق جزءًا كبيرًا من وحدة المعالجة المركزية، فإننا نفكر في التخلي عن شرائح وقت وحدة المعالجة المركزية عند حساب المقاييس.

بالنسبة لـ APISIX، فإن أولوية معالجة الطلبات العادية هي الأعلى، ويجب أن تميل موارد وحدة المعالجة المركزية نحو ذلك. في الوقت نفسه، فإن prometheus:metric_data() ستؤثر فقط على كفاءة الحصول على مقاييس Prometheus Exporter.

في عالم OpenResty، هناك طريقة خفية للتخلي عن شرائح وقت وحدة المعالجة المركزية: ngx.sleep(0). نقدم هذه الطريقة في prometheus:metric_data(). عند معالجة المقاييس، سنتخلى عن شرائح وقت وحدة المعالجة المركزية بعد معالجة عدد معين من المقاييس (مثل 200 مقياس) بحيث يكون للطلبات الجديدة الواردة فرصة للمعالجة.

قدمنا PR لهذا التحسين: feat: performance optimization.

في سيناريو الاختبار الخاص بنا، عندما يصل العدد الإجمالي للمقاييس إلى مستوى 100,000، كانت النتائج التي تم الحصول عليها من اختبار wrk2 قبل إدخال هذا التحسين:

  توزيع التأخير (HdrHistogram - التأخير غير المصحح (تم قياسه دون أخذ التأخيرات في البداية في الاعتبار))
 50.000%   10.21ms
 75.000%   12.03ms
 90.000%   13.25ms
 99.000%   92.80ms
 99.900%  926.72ms
 99.990%  932.86ms
 99.999%  934.40ms
100.000%  934.91ms

نتائج wrk2 بعد التحسين:

  توزيع التأخير (HdrHistogram - التأخير غير المصحح (تم قياسه دون أخذ التأخيرات في البداية في الاعتبار))
 50.000%    4.34ms
 75.000%   12.81ms
 90.000%   16.12ms
 99.000%   82.75ms
 99.900%  246.91ms
 99.990%  349.44ms
 99.999%  390.40ms
100.000%  397.31ms

مؤشر P100 هو حوالي 1/3 إلى 1/2 من ذلك قبل التحسين.

ومع ذلك، هذا لا يحل هذه المشكلة بشكل مثالي. من خلال تحليل الرسم البياني للهب بعد التحسين:

يمكنك أن ترى أن builtin#100 (table.sort) و builtin#92 (string.format) لا يزالان يشغلان عرضًا كبيرًا من المحور الأفقي لأن:

1. prometheus:metric_data() ستقوم أولاً باستدعاء table.sort لفرز جميع المقاييس. عندما تصل المقاييس إلى مستوى 100,000، فإن ذلك يعادل فرز 100,000 سلسلة، ولا يمكن مقاطعة table.sort بواسطة ngx.sleep(0).
2. المكان الذي يتم فيه استخدام string.format و fix_histogram_bucket_labels لا يمكن تحسينه. بعد التواصل مع knyar، علمت أن هذه الخطوات ضرورية لضمان أن prometheus:metric_data() يمكن أن تنتج مقاييس بالتنسيق الصحيح.

حتى الآن، تم استنفاد طرق التحسين على مستوى الكود، ولكن للأسف، المشكلة لم تحل بشكل مثالي. لا يزال هناك تأخير ملحوظ في مؤشرات P100.

ماذا نفعل؟

دعونا نعود إلى القضية الأساسية: prometheus:metric_data() تحتل جزءًا كبيرًا من شرائح وقت وحدة المعالجة المركزية للحساب، مما يضغط على موارد وحدة المعالجة المركزية لمعالجة الطلبات العادية.

في نظام Linux، شرائح الوقت التي تقوم وحدة المعالجة المركزية بتخصيصها لخيط أو عملية؟ بشكل دقيق، إنه خيط، والخيط هو وحدة العمل الفعلية. ومع ذلك، فإن NGINX هو بنية متعددة العمليات ووحيدة الخيط مع خيط واحد فقط في كل عملية.

في هذه المرحلة فكرنا في اتجاه تحسين: نقل prometheus:metric_data() إلى خيوط أخرى (أو بشكل أكثر دقة، عمليات). لذلك قمنا بالتحقيق في اتجاهين:

1. استخدام ngx.run_worker_thread لتشغيل مهام حساب prometheus:metric_data()، أي تسليم المهام المكثفة لوحدة المعالجة المركزية إلى مجموعة الخيوط.
2. استخدام عملية منفصلة للتعامل مع مهام حساب prometheus:metric_data()، هذه العملية لن تتعامل مع الطلبات العادية.

بعد إثبات المفهوم (PoC)، رفضنا الخيار 1 واعتمدنا الخيار 2. تم رفض الخيار 1 لأن ngx.run_worker_thread مناسب فقط لتشغيل مهام حسابية غير مرتبطة بالطلبات، بينما prometheus:metric_data() مرتبطة بالطلبات.

تنفيذ الخيار 2: جعل privileged agent (العملية المميزة) تتعامل مع prometheus:metric_data(). ولكن العملية المميزة لا تستمع إلى أي منافذ أو تتعامل مع أي طلبات. لذلك، نحتاج إلى تعديل العملية المميزة بحيث يمكنها الاستماع إلى المنفذ.

أخيرًا، استخدمنا feat: allow privileged agent to listen port و feat(prometheus): support collect metrics works in the privileged agent لتنفيذ الخيار 2.

استخدمنا APISIX مع هذا التحسين للاختبار، ووجدنا أن تأخير مؤشر P100 قد انخفض إلى نطاق معقول، ولم تعد هناك مشكلة طلبات الذيل الطويل.

  توزيع التأخير (HdrHistogram - التأخير غير المصحح (تم قياسه دون أخذ التأخيرات في البداية في الاعتبار))
 50.000%    3.74ms
 75.000%    4.66ms
 90.000%    5.77ms
 99.000%    9.99ms
 99.900%   13.41ms
 99.990%   16.77ms
 99.999%   18.38ms
100.000%   18.40ms

هذا حل دقيق ويحل المشكلة الأساسية. لاحظنا وتحققنا من هذا الحل في بيئة الإنتاج. لقد أزال ظاهرة طلبات الذيل الطويل، ولم يتسبب في أي استثناءات إضافية.

الخلاصة

عندما كنا نصلح هذه المشكلة، ظهرت فكرة جديدة: هل مكتبة nginx-lua-prometheus مفتوحة المصدر مناسبة لـ APISIX؟

حللنا مشكلة prometheus:metric_data() على جانب APISIX. في الوقت نفسه، وجدنا أيضًا مشاكل أخرى في nginx-lua-prometheus وقمنا بإصلاحها. مثل إصلاح تسرب الذاكرة، و إزالة ذاكرة التخزين المؤقت LRU.

تم تصميم nginx-lua-prometheus في الأصل لـ NGINX، وليس لـ OpenResty والتطبيقات القائمة على OpenResty. ومع ذلك، لا يوجد مشروع مفتوح المصدر في نظام OpenResty يتصل بنظام Prometheus بشكل أكثر نضجًا من nginx-lua-prometheus. لذلك، تم تعزيز nginx-lua-prometheus باستمرار من قبل المجتمع المفتوح المصدر لنظام OpenResty.

ربما يجب علينا استكشاف المزيد وإيجاد طريقة للاتصال بنظام Prometheus دون تعديل الكود المصدري لـ APISIX. على سبيل المثال، تصميم مكتبة تبعية أكثر ملاءمة لـ APISIX، أو الاتصال بمشاريع ناضجة في نظام Prometheus بطريقة معينة، ونقل عملية جمع وحساب المقاييس إلى تلك المشاريع الناضجة.