Profiling Go رمز المشروع وحل مشكلات تخصيص الذاكرة

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



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

توليد حركة مرور عالية

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

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

بعد إجراء بعض التجارب ، ذهبت إلى التكوين التالي لإطلاق Vegeta:

echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 1000 -duration 1m -body evaluate.json 

يقوم هذا الأمر بإطلاق نظام Vegeta في وضع attack ، وإرسال طلبات HTTP POST REST API Flipt بسرعة 1000 طلب في الثانية (وهذا ، من المسلم به ، أنه تحميل خطير) لمدة دقيقة. بيانات JSON المرسلة بواسطة Flipt ليست مهمة بشكل خاص. هناك حاجة فقط لتشكيل الصحيح للطلب. تم تلقي هذا الطلب بواسطة خادم Flipt ، والذي يمكن أن يؤدي إجراء التحقق من الطلب.

يرجى ملاحظة أنني قررت أولاً اختبار /evaluate Flipt /evaluate Evaluation. الحقيقة هي أنه يقوم بتشغيل معظم التعليمات البرمجية التي تنفذ منطق المشروع وتنفذ حسابات الخادم "المعقدة". اعتقدت أن تحليل نتائج نقطة النهاية هذه سيعطيني البيانات الأكثر قيمة في مجالات التطبيق التي يمكن تحسينها.

قياس

الآن بعد أن أصبحت لديّ أداة لتوليد قدر كبير من حركة المرور بشكل كافٍ ، كنت بحاجة لإيجاد طريقة لقياس تأثير حركة المرور هذه على تطبيق قيد التشغيل. لحسن الحظ ، لدى Go مجموعة قياسية جيدة من الأدوات التي يمكنها قياس أداء البرنامج. انها عن حزمة pprof .

لن أخوض في تفاصيل استخدام pprof. لا أعتقد أنني سأفعل ذلك بشكل أفضل من جوليا إيفانز ، التي كتبت هذا المقال الرائع حول ملفات التعريف لـ Go مع pprof (إذا لم تكن قد قرأته ، فأنصحك بالتأكيد بإلقاء نظرة عليه).

نظرًا لأنه يتم تنفيذ جهاز توجيه HTTP في Flipt باستخدام go-chi / chi ، لم يكن من الصعب بالنسبة لي تمكين pprof باستخدام معالج Chi الوسيط المناسب .

لذلك ، في نافذة واحدة ، عمل Flipt بالنسبة لي ، بينما قام Vegeta بملء Flipt بالطلبات ، وعمل في نافذة أخرى. قمت بإطلاق نافذة المحطة الطرفية الثالثة من أجل جمع وفحص بيانات ملفات تعريف الكومة:

 pprof -http=localhost:9090 localhost:8080/debug/pprof/heap 

يستخدم أداة Google pprof ، والتي يمكنها تصور بيانات ملفات التعريف مباشرة في المتصفح.

أولاً ، راجعت inuse_space و inuse_space أجل فهم ما يحدث على الكومة. ومع ذلك ، لم أجد أي شيء رائع. ولكن عندما قررت إلقاء نظرة على alloc_space alloc_objects ، فقد alloc_space شيء ما.


تحليل نتائج التنميط ( الأصلي )

كان هناك شعور بأن هناك شيئًا يسمى flate.NewWriter خصص 19370 ميغابايت من الذاكرة لمدة دقيقة. وهذا ، بالمناسبة ، أكثر من 19 غيغا بايت! من الواضح هنا أن شيئًا غريبًا كان يحدث. لكن ماذا بالضبط؟ إذا نظرت عن كثب إلى المخطط الأصلي أعلاه ، flate.NewWriter أن flate.NewWriter يسمى من gzip.(*Writer).Write ، والذي ، بدوره ، يتم استدعاؤه من middleware.(*compressResponseWriter).Write . أدركت بسرعة أن ما كان يحدث ليس له علاقة بشفرة Flipt. كانت المشكلة في مكان ما في شفرة تشي الوسيطة المستخدمة لضغط الردود من API.

 //   r.Use(middleware.Compress(gzip.DefaultCompression)) 

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

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

لجمع معلومات حول برنامج قيد التشغيل بشكل فعال ، كنت بحاجة إلى تقليل عدد الطلبات في الثانية التي يتم إرسالها إلى التطبيق باستخدام Vegeta ، نظرًا لأن الخادم قد أعطاني socket: too many open files بشكل منتظم socket: too many open files أخطاء socket: too many open files . لقد افترضت أن السبب في ذلك هو أن برنامج ulimit كان منخفضًا جدًا على جهاز الكمبيوتر الخاص بي ، لكنني لا أريد الدخول فيه بعد ذلك.

لذلك ، أعدت تشغيل Vegeta باستخدام هذا الأمر:

 echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 100 -duration 2m -body evaluate.json 

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

في نافذة طرفية أخرى ، قمت بتشغيل هذا الأمر:

 wget 'http://localhost:8080/debug/pprof/trace?seconds=60' -O profile/trace 

نتيجةً لذلك ، كان لديّ ملف يحتوي على بيانات التتبع التي تم جمعها في 60 ثانية. يمكنك فحص هذا الملف باستخدام الأمر التالي:

 go tool trace profile/trace 

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

يمكن العثور على تفاصيل حول go tool trace في هذه المقالة الجيدة.


نتائج تتبع flipt. رسم بياني مسنن لتخصيص الذاكرة على الكومة مرئي بوضوح ( أصلي )

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

الآن جمعت كل الأدلة على "الجريمة" التي أحتاجها ويمكن أن أبدأ بالبحث عن حل لمشكلة تخصيص الذاكرة.

حل المشكلات

من أجل معرفة السبب وراء استدعاء flate.NewWriter أدى إلى العديد من عمليات تخصيص الذاكرة ، كنت بحاجة إلى إلقاء نظرة على شفرة مصدر تشي . لمعرفة إصدار تشي الذي أستخدمه ، قمت بتشغيل الأمر التالي:

 go list -m all | grep chi github.com/go-chi/chi v3.3.4+incompatible 

بعد الوصول إلى الكود المصدري chi / middleware / compress.go @ v3.3.4 ، تمكنت من العثور على الطريقة التالية:

 func encoderDeflate(w http.ResponseWriter, level int) io.Writer {    dw, err := flate.NewWriter(w, level)    if err != nil {        return nil    }    return dw } 

في مزيد من البحث ، اكتشفت أن طريقة flate.NewWriter ، من خلال معالج وسيط ، كانت تسمى لكل استجابة. هذا يتوافق مع كمية هائلة من عمليات تخصيص الذاكرة التي رأيتها في وقت سابق ، وتحميل API مع آلاف الطلبات في الثانية الواحدة.

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

ركضت go get -u -v "github.com/go-chi/chi" ، تمت ترقيته إلى Chi 4.0.2 ، لكن رمز الوسيطة لضغط البيانات بدا ، كما بدا لي ، كما كان من قبل. عندما أجريت الاختبارات مرة أخرى ، لم تختف المشكلة.

قبل وضع حد لهذه المشكلة ، قررت البحث عن المشكلات أو رسائل العلاقات العامة في مستودع Chi التي تشير إلى شيء مثل "الوسيطة ضغط". صادفت أحد العلاقات العامة مع العنوان التالي: "إعادة كتابة مكتبة ضغط الوسيطة". قال مؤلف هذا العنوان التالي: "بالإضافة إلى ذلك ، يتم استخدام sync.Pool للمشفرات ، التي لديها طريقة إعادة تعيين (io.Writer) ، مما يقلل من تحميل الذاكرة."

ها هو! لحسن الحظ ، تمت إضافة PR إلى الفرع master ، ولكن نظرًا لعدم إنشاء إصدار جديد من Chi ، كنت بحاجة إلى تحديث مثل هذا:

 go get -u -v "github.com/go-chi/chi@master" 

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

النتائج

ركضت اختبارات الحمل والتنميط مرة أخرى. هذا سمح لي بالتحقق من أن تحديث تشي حل المشكلة.


الآن flate.NewWriter يستخدم مائة من الكمية المستخدمة سابقا من الذاكرة المخصصة ( الأصلي )

بالنظر مرة أخرى إلى نتائج التتبع ، رأيت أن حجم الكومة ينمو الآن ببطء أكثر. بالإضافة إلى ذلك ، انخفض الوقت اللازم لجمع القمامة.


وداعا - "المنشار" ( الأصلي )

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

النتائج

فيما يلي الاستنتاجات التي خلصت إليها بعد أن تمكنت من العثور على المشكلات المذكورة أعلاه وحلها:

1. يجب ألا تعتمد على الافتراض بأن مكتبات المصادر المفتوحة (حتى الشعبية منها) قد تم تحسينها ، أو أنها ليست لديها مشاكل واضحة.
2. يمكن أن تؤدي مشكلة بريئة إلى عواقب وخيمة ، إلى مظاهر "تأثير الدومينو" ، خاصة في ظل الحمل الثقيل.
3. إذا أمكن ، يجب عليك استخدام sync.Pool .
4. من المفيد الاحتفاظ بأدوات اختبار المشروعات قيد التحميل ولتحديدها.
5. اذهب إلى مجموعة الأدوات والمصدر المفتوح - رائع!

أعزائي القراء! كيف تبحث في أداء مشاريع Go؟