تحديد سبب «البطء» باستخدام PerfView وdotnet-trace ── مدخل عمليّ لتحقيق أداء .NET

في المقال السابق «مدخل إلى سجلّ أحداث Windows وETW»، تناولنا ماهيّة ETW وحتّى تعريف أحداث خاصّة عبر EventSource، واعتبرنا التحليل عبر PerfView «خارج النطاق». هذا المقال امتداد لذلك. نتناول فيه إجراء تحديد الدالّة المسؤولة عن السبب باستخدام PerfView وdotnet-trace، عندما يصبح تطبيق الأعمال «بطيئاً» أو «يستهلك المعالج بالكامل» أو «يتجمّد أحياناً».

ملاحظة: موضوع هذا المقال هو تحقيق المعالج ووقت الاستجابة. أمّا تمييز مشكلة تزايد الذاكرة المستمرّ فهو في «التمييز بين انتظار GC وتسرّب الذاكرة في .NET»، ومشكلة الانهيار (crash) في «قراءة ملفّ crash dump عبر WinDbg + SOS».

1. الخلاصة أوّلاً

• يوجد نوعان لـ«البطء». إمّا استنفاد المعالج بالكامل (CPU bound)، وإمّا أنّ المعالج فارغ لكنّك تنتظر (حظر / blocking). الأوّل يحتاج إلى أخذ عيّنات المعالج (CPU sampling)، والثاني يحتاج إلى جمع ThreadTime (تبديل السياق / context switch)، ومجرّد النظر إلى جمع المعالج الافتراضيّ لا يُظهر سبب الحالة الثانية.¹
• عند التردّد، ابدأ بـ dotnet-trace. أداة عبر المنصّات مبنيّة على EventPipe، ويمكن الجمع بها دون صلاحيّات المدير إن كنتَ نفس المستخدم الذي شغّل العمليّة المستهدَفة.² يمكن فتح ملفّ .nettrace المُجمَّع في PerfView أو Visual Studio.³
• يصبح PerfView ضروريّاً عندما تريد رؤية الجهاز بأكمله، والشيفرة الأصليّة (native)، ووقت الحظر معاً. لأنّه مبنيّ على ETW، يمكنه التعامل مع أحداث النواة (kernel) ومكدّس (stack) الشيفرة الأصليّة أيضاً. في المقابل، يلزم صلاحيّات المدير لبدء جلسة ETW.³
• أخذ عيّنات المعالج يكون افتراضيّاً كلّ 1 ميلي ثانية (لكلّ معالج / processor). اقرأها على أنّ العيّنة الواحدة تعادل نحو 1 ميلي ثانية من زمن المعالج، واحكم بعد تجميع 1,000 عيّنة على الأقلّ كمرجع (يُفضَّل نحو 5,000). قد تكون الدوال الأعلى ترتيباً وعدد العيّنات لا يزال قليلاً محض صدفة.¹
• تفسير الأرقام يبدأ كلّه من التمييز بين inclusive (الذات + من استُدعي) وexclusive (الذات وحدها). الدالّة ذات exclusive الكبير هي «الموضع الذي يستهلك المعالج فعليّاً»، والدالّة ذات inclusive الكبير هي «موضع ثقيل في مكان ما تحتها».
• قبل القياس، ثبِّت «ما الذي يبدو بطيئاً» في عمليّة واحدة. لا يمكن قراءة النتيجة إن جمعتَها وأنت لا تزال عند «بطيء بشكل عامّ». اجمع بعد تثبيت العمليّة والوقت، مثل «إخراج هذا التقرير يستغرق 40 ثانية». يفيد أيضاً «كيفيّة مقارنة سرعة إصدارات مختلفة من برنامج على Windows بشكل صحيح» بخصوص فكرة القياس المقارِن قبل التحسين وبعده.

نلخِّص مدخل التعامل حسب العرَض في جدول قرار.

2. تنظيم علاقة الأدوات ── ETW وEventPipe

تبدو الأدوات الظاهرة كثيرة، لكنّ الأساس اثنان فقط.

• ETW (Event Tracing for Windows): بنية تتبّع (trace) تخترق نظام التشغيل بأكمله. يمكنها التسجيل على نفس المحور الزمنيّ من النواة حتّى التطبيق، لكن بدء جلسة التتبّع وإيقافها يحتاجان صلاحيّات المدير، وهي خاصّة بـ Windows فقط.³
• EventPipe: آليّة تتبّع مدمَجة في وقت تشغيل .NET. لا تحتاج صلاحيّات المدير وتعمل بنفس الطريقة على كلّ نظام تشغيل، لكن في المقابل يقتصر ما تراه على نطاق الشيفرة المُدارة (managed code) ووقت التشغيل، ولا يمكنها أخذ أحداث النواة أو مكدّس الشيفرة الأصليّة.²

عندما يُستوعَب هذا التطابق، يتحدَّد بشكل طبيعيّ التوزيع بين «الجمع أوّلاً وبخفّة عبر dotnet-trace. وإن لم يكفِ، الجمع عبر PerfView مع ETW».

3. قبل الجمع ── انظر الاتّجاه العامّ 10 دقائق عبر dotnet-counters

غالباً ما يكون أسرع من الجمع المباشر للتتبّع، أن تُلقي أوّلاً نظرة على المقاييس (metrics) الرئيسيّة لوقت التشغيل عبر dotnet-counters.⁴

dotnet tool install --global dotnet-counters
dotnet-counters ps
dotnet-counters monitor --process-id <PID> --counters System.Runtime

ما يُنظَر إليه هنا هو استخدام المعالج، وحجم كومة GC (GC heap) وعدد مرّاته، وطول طابور ThreadPool وعدد خيوطه، وعدد الاستثناءات. إن ظهرت اتّجاهات في هذه اللحظة مثل «GC يعمل عدّة مرّات كلّ ثانية» أو «طابور ThreadPool يستمرّ في التزايد»، يمكن تضييق نوع التتبّع الذي يجب جمعه لاحقاً (التخصيص أم الحظر). طريقة قراءة اتّجاهات الذاكرة مشروحة بالتفصيل في مقال التمييز بين انتظار GC وتسرّب الذاكرة.

4. جمع التتبّع عبر dotnet-trace

dotnet-trace أداة جمع مبنيّة على EventPipe.⁵ التثبيت والجمع الأساسيّ كالتالي.

dotnet tool install --global dotnet-trace
dotnet-trace ps
dotnet-trace collect --process-id <PID> --duration 00:00:00:30

عند عدم تحديد أيّ خيار، يُجمَع وفق تشكيلة الملفّ الشخصيّ (profile) الافتراضيّة، التي تتضمّن الأحداث الرئيسيّة لوقت التشغيل وأخذ عيّنات الخيوط. أُلغي الملفّ الشخصيّ المُسمّى cpu-sampling الذي كان موجوداً سابقاً، والافتراضيّ الحاليّ هو مزيج dotnet-common وdotnet-sampled-thread-time.⁵ حسب الاستخدام، يمكن أيضاً اختيار --profile gc-verbose (أخذ عيّنات GC وتخصيص الكائنات) أو --profile gc-collect (تسجيل وقوع GC فقط بعبء منخفض).

لجمع المزوِّد (provider) الخاصّ بـ EventSource الذي أنشأناه في المقال السابق معاً، أضِف --providers.

dotnet-trace collect --process-id <PID> --providers KomuraSoft-OrderService

تصبح نتيجة الجمع ملفّ .nettrace. توجد ثلاث طرق لفتحه: فتحه في Visual Studio أو PerfView، أو تحويله إلى صيغة speedscope لعرضه في المتصفّح.⁵

dotnet-trace convert trace.nettrace --format Speedscope

صيغة speedscope عرض رسم بيانيّ إطاريّ (frame graph) خفيف يمكن فتحه في speedscope.app، وهو مناسب للنظر بشكل حَدسيّ إلى «تحت أيّ دالّة استُهلك الوقت». ولأنّ عارض المكدّس (stack viewer) الخاصّ بـ PerfView أقوى للتدقيق الذي يحدِّد اسم الدالّة، ننتقل إلى الفصل التالي.

5. تحقيق المعالج عبر PerfView ── طريقة قراءة عارض المكدّس

PerfView أداة تحقيق أداء تنشرها Microsoft مجّاناً، وتعمل بمجرّد تنزيل PerfView.exe وحده من صفحة إصدارات GitHub (دون تثبيت).⁶

5.1 الجمع

الأسلوب الأساسيّ هو فتح الحوار عبر «Collect > Collect» في الواجهة الرسوميّة، ثمّ Start Collection ← إعادة إنتاج العمليّة المستهدَفة ← Stop Collection. عبر سطر الأوامر، يكون الشكل كالتالي (وبما أنّه يبدأ جلسة ETW، شغِّله كمدير³).

PerfView collect /nogui /acceptEULA /maxCollectSec:30

يتضمّن الجمع الافتراضيّ عيّنة معالج (مع مكدّس الاستدعاء) كلّ 1 ميلي ثانية على كلّ معالج، والأحداث الرئيسيّة لـ CLR.¹ العبء الإضافيّ (overhead) أثناء الجمع بالتشكيلة الافتراضيّة يبلغ عموماً بضعة بالمئة تقريباً.⁷

5.2 قراءة CPU Stacks

افتح نتيجة الجمع (.etl.zip)، واختر العمليّة المستهدَفة في «CPU Stacks»، فيُفتَح عارض المكدّس. أوّل ما يُنظَر إليه عمودان في تبويب By Name.

• Exc (exclusive): عدد العيّنات التي كانت الدالّة نفسها قيد التنفيذ فيها. الموضع الذي يستهلك المعالج فعليّاً.
• Inc (inclusive): مجموع عدد العيّنات الخاصّة بالدالّة وكلّ ما استُدعي منها. يدلّ على أنّ موضعاً ما تحتها ثقيل.

النمط الصحيح للقراءة هو النظر من أعلى Exc وتمييز «هل هذه شيفرتك أم وقت التشغيل/المكتبة». إن ظهرت شيفرتك في أعلى Exc، فإنّ خوارزميّة تلك الدالّة أو حلقتها هي الهدف المباشر. وإن ظهر أعلى Exc عناصر من نوع System.String أو مُسلسِل (serializer) JSON، تتبَّعه عبر Inc في تبويب Callers لتحديد من أين في شيفرتك يُستدعى بكثرة.

المهمّ أيضاً هو التحقّق من عدد العيّنات نفسه. بما أنّ عيّنة المعالج إحصاء بفاصل 1 ميلي ثانية، فإن قلّ عدد العيّنات تتأثّر النتيجة بالصدفة. كحدّ استرشاديّ، احكم بعد تجميع 1,000 عيّنة على الأقلّ، ويُفضَّل نحو 5,000، وإن لم يكفِ، كرِّر العمليّة المستهدَفة وأطِل وقت الجمع.¹

ملاحظة: إن ظهرت أسماء دوال وحدة شركتك كعناوين فقط، فالرموز (PDB) غير محلولة. تجهيز PDB الخاصّ بمُنتَجات البناء لديك يصبح مباشرةً قدرة على التحقيق. هذا الموضوع مشروح بالتفصيل في «PDB (قاعدة بيانات البرنامج) ما هي؟».

6. «المعالج فارغ لكنّ الأداء بطيء» ── رؤية وقت الحظر عبر ThreadTime

أكثر من نصف حالات «البطء» في العمل الفعليّ ليست بسبب المعالج بل بسبب الانتظار. انتظار القفل (lock)، وانتظار استجابة قاعدة البيانات أو HTTP، وإدخال/إخراج الملفّات، وانتظار شبه توقّف تامّ (deadlock) بسبب Task.Result. هذا النوع من المشاكل لا يظهر في عيّنة المعالج على أنّه «وقت لم يُستخدَم فيه المعالج أصلاً»، فلا يظهر السبب في الجمع الافتراضيّ.

في PerfView، عند تفعيل خيار Thread Time أثناء الجمع، تُسجَّل أحداث تبديل السياق (context switch) إضافةً، ويصبح ممكناً تتبّع «الوقت الذي استخدم فيه كلّ خيط (thread) المعالج» و«الوقت الذي كان فيه محظوراً» معاً.¹

PerfView collect /nogui /acceptEULA /threadTime /maxCollectSec:30

في التحليل، افتح عرض «Thread Time Stacks». إنّه عارض المكدّس نفسه الموجود في CPU Stacks، لكن الفارق أنّ العيّنة لا تمثِّل زمن المعالج فقط، بل تتضمّن أيضاً BLOCKED_TIME (الوقت الذي كان فيه محظوراً). بعد التضييق إلى النطاق الزمنيّ للعمليّة البطيئة، إن نظرت إلى أيّ مكدّس (أيّ انتظار) تراكم فيه BLOCKED_TIME الخاصّ بالخيط المسؤول عن المعالجة، تحصل على تفصيل من نوع «من أصل 40 ثانية إجماليّة، 35 ثانية كانت انتظاراً لهذا الاستدعاء عبر HTTP».

أعراض من نوع تجمّد الواجهة (UI) (لا استجابة لعدّة ثوانٍ عند التفاعل) غالباً ما يكون سببها حظر خيط الواجهة. بعد تحديد وجهة حظر خيط الواجهة عبر ThreadTime، اتّجه كحلّ دائم إلى تصميم يُحوِّل انتظار المزامنة إلى غير متزامن. راجع «تنظيم async وخيط الواجهة في WPF/WinForms في صفحة واحدة» بخصوص هذا التنظيم على مستوى التصميم.

ملاحظة: بما أنّ جمع ThreadTime يسجِّل حدثاً عند كلّ تبديل سياق، فإنّ حجم البيانات يزداد بوضوح مقارنةً بالجمع الافتراضيّ. اجعل وقت الجمع قصيراً، وتجنَّب الجمع الطويل في بيئة الإنتاج.

7. الجمع مع EventSource ── تقسيم «أيّ فترة بطيئة» بلغة العمل

كلّ من CPU Stacks وThread Time هما تجميع للعمليّة بأكملها. إن أردتَ التقسيم بوحدة معالجة العمل، مثل «أين تحديداً داخل معالجة أمر واحد يكمن البطء»، فإنّ أحداث Start/Stop الخاصّة بـ EventSource المشروحة في المقال السابق تصبح فعّالة.

• زوِّد التطبيق بأحداث مثل OrderProcessingStart / OrderProcessingStop (للتنفيذ، راجع المقال السابق)
• تحقّق من وقت ذلك الحدث في عرض «Events» الخاصّ بـ PerfView، وضيِّق النطاق الزمنيّ (مرشّحَي Start/End) لعارض المكدّس إلى تلك الفترة
• اقرأ تفصيل المعالج/وقت الحظر ضمن النطاق المُضيَّق

بهذه الطريقة، يمكن تحليل «تلك المرّة البطيئة» وحدها كهدف، دون أن تُغرَق بضوضاء الأوقات العاديّة. يمكن جمع الأحداث الخاصّة بنفس الطريقة عبر dotnet-trace أيضاً، فإذا زوّدتَ التطبيق بأداة القياس مرّة واحدة، تصبح نفس طريقة التحقيق صالحة سواء على جهاز التطوير أو في الإنتاج. والانطباع من العمل الفعليّ هو أنّ صعوبة تحقيق الأداء تتحدَّد بـ«هل يوجد نقطة رصد في جانب التطبيق» أكثر من مهارة استخدام الأداة.

الخلاصة

• نقطة الانطلاق هي تقسيم «البطء» إلى CPU bound وحظر (blocking). الأوّل لا يظهر إلّا بأخذ عيّنات المعالج (عيّنة واحدة ≈ 1 ميلي ثانية)، والثاني لا يظهر إلّا بجمع ThreadTime.
• الأساس هو التوزيع بين dotnet-trace القابل للاستخدام دون صلاحيّات المدير أوّلاً، وPerfView عند الحاجة إلى الجهاز بأكمله والشيفرة الأصليّة ووقت الحظر. الجمع بين قراءة .nettrace المُجمَّع في PerfView أمر شائع أيضاً.
• جوهر قراءة عارض المكدّس هو التمييز بين exclusive وinclusive، مع التحقّق دائماً من كفاية عدد العيّنات.
• تجهيز إمكانيّة تقسيم فترة معالجة العمل عبر أحداث خاصّة في EventSource يرفع دقّة التحقيق درجة أعلى.

تتعامل شركة Komura Soft LLC مع تحقيق مشاكل الأداء في تطبيقات أعمال Windows من نوع «بطيء» أو «متجمّد» أو «يستهلك المعالج بالكامل»، والاستشارة بخصوص القياس والتصميم اللازمَين لتسهيل القياس. إن توفّرت خطوات إعادة الإنتاج وملفّ التتبّع، يمكن أيضاً تكليفنا بالتحليل وحده انطلاقاً من ذلك.

مقالات ذات صلة

• مدخل إلى سجلّ أحداث Windows وETW ── وضع سجلّات تطبيق الأعمال على آليّة نظام التشغيل القياسيّة
• التمييز بين انتظار GC وتسرّب الذاكرة في .NET ── إجراءات عمليّة لمراقبة الذاكرة المتزايدة ومقارنتها وإثباتها
• قراءة ملفّ crash dump عبر WinDbg + SOS ── مدخل عمليّ للتحليل بعد الجمع
• مدخل إلى جمع ملفّات crash dump في Windows - WER/ProcDump/WinDbg
• PDB (قاعدة بيانات البرنامج) ما هي؟ ── فهم معلومات التصحيح والرموز (symbols) وSource Link
• كيفيّة مقارنة سرعة إصدارات مختلفة من برنامج على Windows بشكل صحيح
• تنظيم async وخيط الواجهة في WPF/WinForms في صفحة واحدة

مجالات الاستشارة ذات الصلة

• تحقيق الأخطاء وتحليل الأسباب
• تطوير تطبيقات Windows
• الاستشارة التقنيّة ومراجعة التصميم
• التواصل معنا

روابط مرجعيّة

مقالات ذات صلة

أحدث المقالات التي تشترك في نفس الوسوم. عمّق فهمك بمواضيع مرتبطة.

أين يتصل هذا الموضوع

ترتبط هذه المقالة بشكل طبيعي بصفحات الخدمات التالية.

الأسئلة الشائعة

أسئلة شائعة حول موضوع هذه المقالة.

أيّ الأداتَين ينبغي استخدامها، PerfView أم dotnet-trace؟

يُنصَح بالبدء بتجربة dotnet-trace أوّلاً. يمكن استخدامه دون صلاحيّات المدير (administrator)، ويمكنه الجمع مستهدفاً العمليّة المعنيّة فقط، والتشغيل بسطر أمر واحد. في المقابل، إن أردتَ رؤية مكدّس (stack) الشيفرة الأصليّة (native)، أو حالة الجهاز كاملةً (أثر العمليّات الأخرى أو النواة kernel)، أو تتبّع وقت الحظر (blocking) بوحدة تبديل السياق (context switch)، فيلزم PerfView المبنيّ على ETW. ومن الشائع أيضاً الجمع بين الأداتَين: جمع ملفّ `.nettrace` ثمّ فتحه في PerfView للتحليل.

ما العلاقة بأداة التحليل (profiler) في Visual Studio؟

إن كانت المشكلة قابلة لإعادة الإنتاج على جهاز التطوير، فأدوات استخدام المعالج والذاكرة في Visual Studio أسهل استخداماً، وهي كافية غالباً كبداية. يصبح PerfView أو dotnet-trace فعّالَين في المواقف التي لا يمكن فيها تثبيت Visual Studio (جهاز تحقّق أو جهاز إنتاج)، أو عند الرغبة في فصل الجمع عن التحليل على جهازَين مختلفَين، أو عند الرغبة في رؤية أحداث ETW (بما فيها EventSource الخاصّ بك أو أحداث النواة) أيضاً. كما يستطيع Visual Studio فتح ملفّ `.nettrace` الذي يُخرِجه dotnet-trace.

هل يجوز تشغيلها على خادم الإنتاج؟

صُمِّمت كلتا الأداتَين مع افتراض الجمع القصير المدى في بيئة الإنتاج، لكن ذلك ليس دون شروط. اتّبع الإجراء التالي: حدِّد وقت الجمع بعشرات الثواني إلى بضع دقائق، وجرِّب أوّلاً نفس الأمر في بيئة التحقّق للتأكّد من العبء الإضافيّ (overhead) وحجم الملفّ، وتحقّق من المساحة المتبقّية على القرص. بوجه خاصّ، يحتوي جمع ThreadTime (تبديل السياق) وتتبّع التخصيص (allocation trace) على كمّ كبير من الأحداث، ويتضخّم حجم الملفّ سريعاً. كذلك، بما أنّ التتبّع (trace) يحتوي معلومات مثل معاملات سطر الأوامر، يلزم الحذر أيضاً في التعامل مع الملفّ المُلتقَط.

كيف يُوزَّع الاستخدام بينها وبين WPR/WPA؟

WPR (Windows Performance Recorder) وWPA (Windows Performance Analyzer) أداتا تحقيق أقرب إلى نظام التشغيل، مبنيّتان على نفس أساس ETW. في التحليل المفصَّل على مستوى نظام التشغيل بأكمله - كإدخال/إخراج القرص، والطاقة، ووقت بدء التشغيل - يتفوّق WPR/WPA، بينما في تحقيق المعالج وGC ووقت الحظر لتطبيق .NET، يكون PerfView المُحسَّن لعرض الشيفرة المُدارة (managed code) أسهل قراءةً. إن كان الهدف تحقيق تطبيق أعمال، فإنّ PerfView وdotnet-trace يكفيان في معظم الحالات.

الملف الشخصي للمؤلف

صفحة الملف الشخصي لمؤلف المقالة.

غو كومورا

مؤسّس شركة كومورا سوفت ذ.م.م.

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