قصة Coredump حول NGINX ctx و error_page

تعتبر الانهيارات (Coredumps) في بيئة الإنتاج مخيفة للمهندسين، خاصة عندما تحدث في منتصف الليل. لقد مررت بهذه التجربة بنفسي منذ أكثر من عقد من الزمن. في محاولة لتحديد هذا الخطأ "الشبح" الذي يظهر فقط في الليل، عاد الفريق بأكمله إلى المنزل للنوم في فترة ما بعد الظهر وعاد إلى الشركة في الساعة 12 صباحًا لانتظار الانهيار وفحص كل خدمة واحدة تلو الأخرى. تخيل ليلة مظلمة ومبنى مكتبي مع عدد قليل من أجهزة العمل المضاءة، تشاهد الشاشة التي تنبض باستمرار للبيانات والسجلات – تجربة مكثفة ومثيرة. بقينا لثلاث ليالٍ قبل أن نحدد الخطأ ونحله، وهي تجربة لا تُنسى.

لم نكن نعلم أننا سنمر بهذه التجربة مرة أخرى. لكن هذه المرة لم تكن الخدمة الخاصة بنا، بل كانت خدمة العميل عبر الإنترنت هي التي تعرضت لانهيار. وكان هذا أكثر تحدياً من بيئتنا القابلة للتحكم:

• حدث الخطأ فقط في بيئة إنتاج المستخدم، ولم يتمكن المستخدم من إعادة إنتاج الخطأ حتى في بيئته ما قبل الإنتاج وبيئة الاختبار.
• كان لدى المستخدم كود مخصص فوق Apache APISIX مفتوح المصدر، ولم يكن مرئيًا حتى تم توقيع اتفاقية عدم الإفصاح (NDA) بشكل منفصل.
• لم يكن من الممكن إضافة سجلات تصحيح (debug logs).
• حدث الخطأ فقط في الساعة 3 صباحًا، مما تطلب موارد إضافية من العميل للتعامل معه على الفور.

باختصار، كانت هذه المشكلة غير قابلة للإعادة، بدون كود مصدري كامل، وبدون بيئة للاختبار. ومع ذلك، كان علينا تحديد الخطأ، وإيجاد طريقة لإعادة إنتاجه وتقديم إصلاح في النهاية. خلال العملية، واجهنا العديد من التحديات وتعلمنا الكثير منها. هنا ننشر بعض النقاط المثيرة للاهتمام التي واجهناها أثناء عملية التصحيح. آمل أن توفر بعض التوجيه عند تصحيح الأخطاء لـ NGINX وAPISIX.

وصف المشكلة

بعد أن قام المستخدم بترقية APISIX من الإصدار 2.4.1 إلى الإصدار 2.13.1، حدثت انهيارات بشكل دوري، مع ظهور الرسالة التالية:

من رسالة الانهيار، يمكننا أن نرى أن خطأ التجزئة (segmentation fault) يحدث في lua-var-nginx-module. وهنا البيانات المقابلة (جزئيًا) في الذاكرة:

#0  0x00000000005714d4 in ngx_http_lua_var_ffi_scheme (r=0x570d700, scheme=0x7fd2c241a760)
    at /tmp/vua-openresty/openresty-1.19.3.1-build/openresty-1.19.3.1/../lua-var-nginx-module/src/ngx_http_lua_var_module.c:152
152        /tmp/vua-openresty/openresty-1.19.3.1-build/openresty-1.19.3.1/../lua-var-nginx-module/src/ngx_http_lua_var_module.c: No such file or directory.
(gdb) print *r
$1 = {signature = 0, connection = 0x0, ctx = 0x15, main_conf = 0x5adf690, srv_conf = 0x0, loc_conf = 0x0, read_event_handler = 0xe, write_event_handler = 0x5adf697,
  cache = 0x2, upstream = 0x589c15, upstream_states = 0x0, pool = 0x0, header_in = 0xffffffffffffffff}

يمكننا أن نرى أن البيانات في الذاكرة بها مشكلة.

بعض الأفكار قبل التحليل

عادة ما يحدث خطأ التجزئة في سيناريوهين:

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

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

بالنسبة للسيناريو الثاني، نظرًا لأنه ليس من الواضح مكان حدوث الخطأ في البداية، قد لا يكون الكود الذي أنشأ الخطأ والكود الذي أثار خطأ التجزئة في نفس المكان، بل قد يكونان غير مرتبطين تمامًا، مما يجعل تحديد المشكلة صعبًا. يمكننا فقط جمع المزيد من المعلومات السياقية المتعلقة بالانهيار، مثل:

• تفاصيل تكوين APISIX الحالي.
• مرحلة معالجة الطلب الحالي.
• تفاصيل الطلب الحالي.
• عدد الاتصالات المتزامنة.
• سجل الأخطاء.

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

التحليل

1. فحص سياق الأخطاء

بعد التحليل الدقيق، وجدنا أن الخطأ يحدث عادة بين الساعة 3 صباحًا و4 صباحًا، مع ظهور رسالة الانهيار التالية:

في النهاية، أدركنا أن سجل الخطأ مرتبط بعمليات المستخدم. بسبب أسباب معينة، يتم مسح جميع الرسائل الصادرة (upstream messages) في هذا الوقت. لذا، اشتبهنا في أن المشكلة مرتبطة بعمليات مسح/إعادة تعيين الرسائل الصادرة، وأن الانهيار قد يكون ناتجًا عن دخول فرع استثنائي بعد إرجاع الخطأ.

2. الحصول على مكدس استدعاءات Lua

نظرًا لأن GDB لا يمكنه تتبع مكدس استدعاءات Lua، لم نتمكن من تحديد أي استدعاء أنشأ الخطأ. لذا، كان أول شيء نحتاج إلى فعله هو الحصول على مكدس استدعاءات Lua؛ كان لدينا طريقتان للحصول على مكدس الاستدعاءات:

1. في مكتبة lua-var-nginx-module، إضافة كود لطباعة مكدس الاستدعاءات (print(debug.traceback(...)). العيب هو أنه سيولد الكثير من سجلات الأخطاء، مما يؤثر سلبًا على بيئة الإنتاج.
2. استخدام openresty-gdb-utils التي تحتفظ بها API7.ai، هذه الأدوات تستخدم DSL من GDB وامتداد بايثون لتعزيز قدرة GDB على تحليل مكدس استدعاءات Lua. لاحظ، ستحتاج إلى تشغيل رمز التصحيح (debug symbol) في وقت التجميع. وهو مضمن بشكل افتراضي في APISIX.

ثم، حصلنا على مكدس الاستدعاءات التالي.

بدمج مكدس استدعاءات Lua وC، يمكننا أن نجد أن الانهيار حدث لأن المستخدم استدعى ngx.ctx.api_ctx.var.scheme في مكون Prometheus. ومع ذلك، كان سبب الانهيار غير واضح، وكنا بحاجة إلى تحليل المزيد.

3. التخزين المؤقت تسبب في المشكلة

حدث الخطأ عند الوصول إلى متغير من ngx.ctx.api_ctx.var الذي قام باستدعاء في lua-var-nginx-module كما وصفنا أعلاه. لزيادة الكفاءة، قام بتخزين الطلب الحالي مؤقتًا. تذكرنا أن الخطأ حدث عندما كانت قيمة جسم الطلب بها استثناء، لذا كانت صلاحية الطلب المخزن مؤقتًا موضع شك. للتحقق من هذه الفكرة، أوقفنا البرنامج عن أخذ الذاكرة المخزنة مؤقتًا، ولكننا قمنا بإعادة جلب الطلب في كل مرة.

else
    --val = get_var(key, t._request)
    val = get_var(key, nil)              <============ t._request تغيير إلى nil
end

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

4. الخطأ في ngx.ctx

تم حفظ جسم الطلب المخزن مؤقتًا في ngx.ctx، والمكان الوحيد الذي قام بتعديل ngx.ctx كان في apisix/init.lua.

function _M.http_header_filter_phase()
    if ngx_var.ctx_ref ~= '' then
        -- منع تسرب الجدول
        local stash_ctx = fetch_ctx()

        -- إعادة توجيه داخلي، لذا يجب تطبيق ctx
        if ngx_var.from_error_page == "true" then
            ngx.ctx = stash_ctx          <================= هنا
        end
    end

    core.response.set_header("Server", ver_header)

    local up_status = get_var("upstream_status")
    if up_status then
        set_resp_upstream_status(up_status)
    end

لماذا كنا بحاجة إلى استعادة ngx.ctx هنا؟ لأن ngx.ctx يتم تخزينه في سجل Lua، ويمكن العثور على ngx.ctx المقابل من خلال فهرس السجل. وكان الفهرس مخزنًا في عضو ctx من بنية طلب NGINX. في كل مرة يتم فيها إعادة توجيه داخلي، يقوم NGINX بمسح ctx، وبالتالي لا يمكن العثور على الفهرس.

لحل هذه المشكلة، قام APISIX بإنشاء جدول، قام الجدول بحفظ ngx.ctx الحالي قبل إعادة التوجيه، ثم استخدم ngx.var لتسجيل فهرس ngx.ctx في هذا الجدول، وعندما يحتاج إلى الاستعادة، يمكننا الحصول على ngx.ctx مباشرة من الجدول.

تم تشغيل الكود في الشكل أعلاه فقط عندما قام المستخدم بتكوين تعليمات error_page، وبعد حدوث خطأ بعد إعادة التوجيه الداخلية.

وكنا نعلم بالتحديد أن المستخدم قام بتشغيل تعليمات error_page بعد الترقية، بالإضافة إلى الخطأ الذي حدث من تغيير الرسائل الصادرة الذي وصفناه أعلاه. بدا أن كل الأشياء مرتبطة. هل كان ngx.ctx هو الذي أنشأ الخطأ أثناء عملية معالجة الخطأ؟

5. لماذا يحتوي ngx.ctx على خطأ

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

كان هذا بوضوح خطأ! حسنًا، هذا لأن ngx.ctx يحتاج إلى الاستعادة بعد إعادة التوجيه. وكيف تمت عملية استعادة ngx.ctx؟ أين حدث الخطأ في ngx.ctx في البداية؟ الآن كانت هناك الكثير من الشكوك، وكنا بحاجة إلى جمع المزيد من البيانات.

بعد المناقشة، أضفنا سجلًا ثانيًا في الإنتاج، واكتشفنا أنه عند حدوث الخطأ بعد إعادة توجيه داخلية، لم تمر ngx.ctx بعملية الاستعادة، بل تسببت في انهيار مباشرة!

كانت هذه ظاهرة محيرة لأنه إذا لم يتم استعادة ngx.ctx بعد إعادة التوجيه، فسيكون ngx.ctx فارغًا/غير موجود. وكان هناك كود يتحقق من القيم الفارغة؛ لا ينبغي أن يثير كود الانهيار في المكون.

local function common_phase(phase_name)
    local api_ctx = ngx.ctx.api_ctx
    if not api_ctx then              <============ هنا
        return
    end

    plugin.run_global_rules(api_ctx, api_ctx.global_rules, phase_name)

إذن، هل كانت إعادة التوجيه الداخلية لـ error_page هي التي تسببت في مشكلة ngx.ctx؟

6. الاستنتاج الأولي

بعد التحليل والفحص، حصلنا على فهم أساسي للعملية الخاطئة.

فشل set_upstream وأعاد التوجيه إلى مرحلة معالجة الخطأ في error_page، وكان ngx.ctx المتوقع فارغًا يحتوي على قيمة غير متوقعة. وبسبب خطأ في APISIX، لم يتم استعادة ngx.ctx قبل إعادة التوجيه، مما تسبب في أن ngx.ctx يحتوي على بيانات غير صالحة عند الوصول، مما أدى إلى الانهيار. لحل هذه المشكلة، كنا بحاجة فقط إلى استعادة ngx.ctx بعد إعادة التوجيه؛ يتم توفير التنفيذ التفصيلي لهذا الالتزام في نهاية المقال للرجوع إليه.

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

7. إعادة الإنتاج الناجحة

من ما كنا نعرفه، لم نتمكن من إعادة إنتاج المشكلة. بعد التحليل، قررنا التحقق من مكانين من الأماكن التالية:

• هل كانت إعادة التوجيه الداخلية تحتوي على فروع خاصة للمعالجة؟
• هل كان ngx.ctx يحتوي على فروع خاصة للمعالجة؟

بالنسبة للنقطة الأولى، أثناء معالجة كل وحدة تصفية (filter module) من NGINX، قد يكون لديها بعض الفروع الاستثنائية التي أثرت على أعضاء ctx من جسم الطلب، مما أثر على ngx.ctx. قمنا بفحص وحدات المستخدم المترجمة في NGINX للبحث عن فروع استثنائية محتملة ولكن لم نجد مشاكل مشابهة.

بالنسبة للنقطة الثانية، بعد التحقيق، وجدنا أن أثناء مصافحة SSL، كان ngx.ctx به مشكلة من إعادة الاستخدام. إذا لم تتمكن مرحلة HTTP من الحصول على ngx.ctx، فستحاول الحصول عليه من مرحلة SSL. مرحلة SSL لديها ngx.ctx الخاص بها، وقد يسبب ذلك مشاكل لـ ngx.ctx.

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

1. نفس إصدار APISIX الذي يستخدمه المستخدم.
2. تشغيل شهادة SSL.
3. إنشاء خطأ داخلي يؤدي إلى تشغيل error_page (مثل طلب upstream عندما لا يوجد أي شيء).
4. اتصال طويل الأمد.
5. مكون Prometheus (حدث الانهيار في المكون للمستخدم).

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

الخلاصة

السبب الجذري لهذه المشكلة: لأن ngx.ctx لم يتم استعادته بعد الدخول إلى error_page، جميع الطلبات على الاتصال الطويل الأمد أعادت استخدام نفس ngx.ctx في مرحلة SSL. في النهاية، تسبب ngx.ctx في احتواء بيانات غير صالحة وتم إنشاء انهيار.

في المتابعة، قمنا أيضًا باقتراح حل مقابل لهذه المشكلة: لضمان أن ngx.ctx يمكن استعادته بشكل طبيعي بعد إعادة التوجيه الداخلية. يرجى الرجوع إلى PR المحدد.

إذا كان APISIX الخاص بك يستخدم وظائف تتضمن إعادة توجيه داخلية مثل error_page، يرجى الترقية إلى أحدث إصدار في أقرب وقت ممكن.

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