باستخدام ftrace

ftrace هي أداة تصحيح الأخطاء لفهم ما يجري داخل نواة Linux. توضح الأقسام التالية بالتفصيل وظيفة ftrace الأساسية، واستخدام ftrace مع atrace (الذي يلتقط أحداث kernel)، وftrace الديناميكي.

للحصول على تفاصيل حول وظيفة ftrace المتقدمة التي لا تتوفر من systrace، راجع وثائق ftrace على <kernel tree>/Documentation/trace/ftrace.txt .

التقاط أحداث النواة باستخدام atrace

يستخدم atrace ( frameworks/native/cmds/atrace ) ftrace لالتقاط أحداث kernel. بدوره، يستخدم systrace.py (أو run_systrace.py في الإصدارات اللاحقة من Catapult ) adb لتشغيل atrace على الجهاز. يقوم atrace بما يلي:

• يقوم بإعداد تتبع وضع المستخدم عن طريق تعيين خاصية ( debug.atrace.tags.enableflags ).
• لتمكين وظيفة ftrace المطلوبة عن طريق الكتابة إلى عقد ftrace sysfs المناسبة. ومع ذلك، نظرًا لأن ftrace يدعم المزيد من الميزات، فيمكنك تعيين بعض عقد sysfs بنفسك ثم استخدام atrace.

باستثناء تتبع وقت التمهيد، اعتمد على استخدام atrace لتعيين الخاصية إلى القيمة المناسبة. الخاصية عبارة عن قناع نقطي ولا توجد طريقة جيدة لتحديد القيم الصحيحة بخلاف النظر إلى الرأس المناسب (والذي يمكن أن يتغير بين إصدارات Android).

تمكين أحداث ftrace

توجد عقد ftrace sysfs في /sys/kernel/tracing ويتم تقسيم أحداث التتبع إلى فئات في /sys/kernel/tracing/events .

لتمكين الأحداث على أساس كل فئة، استخدم:

echo 1 > /sys/kernel/tracing/events/irq/enable

لتمكين الأحداث على أساس كل حدث، استخدم:

echo 1 > /sys/kernel/tracing/events/sched/sched_wakeup/enable

إذا تم تمكين الأحداث الإضافية عن طريق الكتابة إلى عقد sysfs، فلن تتم إعادة تعيينها بواسطة atrace. أحد الأنماط الشائعة لإحضار جهاز Qualcomm هو تمكين نقاط التتبع kgsl (GPU) و mdss (خط أنابيب العرض) ثم استخدام atrace أو systrace :

adb shell "echo 1 > /sys/kernel/tracing/events/mdss/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/kgsl/enable"
./systrace.py sched freq idle am wm gfx view binder_driver irq workq ss sync -t 10 -b 96000 -o full_trace.html

يمكنك أيضًا استخدام ftrace بدون atrace أو systrace، وهو أمر مفيد عندما تريد تتبعات kernel فقط (أو إذا كنت قد أخذت وقتًا لكتابة خاصية التتبع لوضع المستخدم يدويًا). لتشغيل ftrace فقط:

1. قم بتعيين حجم المخزن المؤقت على قيمة كبيرة بما يكفي لتتبعك:

   echo 96000 > /sys/kernel/tracing/buffer_size_kb
   

2. تمكين التتبع:

   echo 1 > /sys/kernel/tracing/tracing_on
   

3. قم بإجراء الاختبار، ثم قم بتعطيل التتبع:

   echo 0 > /sys/kernel/tracing/tracing_on
   

4. تفريغ التتبع:

   cat /sys/kernel/tracing/trace > /data/local/tmp/trace_output
   

يعطي Trace_output التتبع في شكل نص. لتصوره باستخدام Catapult، احصل على مستودع Catapult من GitHub وقم بتشغيل Trace2html:

catapult/tracing/bin/trace2html ~/path/to/trace_file

بشكل افتراضي، يقوم هذا بكتابة trace_file.html في نفس الدليل.

الأحداث المترابطة

غالبًا ما يكون من المفيد النظر إلى تصور Catapult وسجل ftrace في وقت واحد؛ على سبيل المثال، بعض أحداث ftrace (خاصة الأحداث الخاصة بالبائع) لا يتم تصورها بواسطة Catapult. ومع ذلك، فإن الطوابع الزمنية لـ Catapult تتعلق إما بالحدث الأول في التتبع أو بطابع زمني محدد تم تفريغه بواسطة atrace، بينما تعتمد الطوابع الزمنية الأولية لـ ftrace على مصدر ساعة مطلق محدد في Linux kernel.

للعثور على حدث ftrace معين من حدث Catapult:

1. افتح سجل ftrace الخام. يتم ضغط الآثار الموجودة في الإصدارات الأخيرة من systrace افتراضيًا:
   • إذا قمت بالتقاط systrace الخاص بك باستخدام --no-compress ، فهذا موجود في ملف html في القسم الذي يبدأ بـ BEGIN TRACE.
   • إذا لم يكن الأمر كذلك، فقم بتشغيل html2trace من شجرة Catapult ( tracing/bin/html2trace ) لإلغاء ضغط التتبع.
2. ابحث عن الطابع الزمني النسبي في تصور Catapult.
3. ابحث عن سطر في بداية التتبع يحتوي على tracing_mark_sync . يجب أن يبدو مثل هذا:

   <5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286
   

   
   إذا لم يكن هذا الخط موجودًا (أو إذا استخدمت ftrace بدون atrace)، فستكون التوقيتات نسبية من الحدث الأول في سجل ftrace.
   1. أضف الطابع الزمني النسبي (بالمللي ثانية) إلى القيمة الموجودة في parent_ts (بالثواني).
   2. ابحث عن الطابع الزمني الجديد.

يجب أن تضعك هذه الخطوات في الحدث (أو على الأقل قريبًا جدًا منه).

باستخدام ftrace الديناميكي

عندما لا يكون systrace وftrace القياسي كافيين، فهناك حل أخير متاح: Dynamic ftrace . يتضمن ftrace الديناميكي إعادة كتابة كود kernel بعد التمهيد، ونتيجة لذلك فهو غير متوفر في نواة الإنتاج لأسباب أمنية. ومع ذلك، فإن كل خطأ صعب في الأداء في عامي 2015 و2016 كان في النهاية سببًا جذريًا باستخدام ftrace الديناميكي. إنه قوي بشكل خاص لتصحيح أخطاء حالات النوم غير المنقطعة لأنه يمكنك الحصول على تتبع المكدس في النواة في كل مرة تضغط فيها على الوظيفة التي تؤدي إلى نوم غير متقطع. يمكنك أيضًا تصحيح أخطاء الأقسام مع تعطيل المقاطعات والإجراءات الوقائية، وهو ما يمكن أن يكون مفيدًا جدًا لإثبات المشكلات.

لتشغيل ftrace الديناميكي، قم بتحرير defconfig الخاص بالنواة:

1. قم بإزالة CONFIG_STRICT_MEMORY_RWX (إذا كان موجودًا). إذا كنت تستخدم الإصدار 3.18 أو الأحدث وarm64، فهذا ليس موجودًا.
2. أضف ما يلي: CONFIG_DYNAMIC_FTRACE=y وCONFIG_FUNCTION_TRACER=y وCONFIG_IRQSOFF_TRACER=y وCONFIG_FUNCTION_PROFILER=y وCONFIG_PREEMPT_TRACER=y
3. إعادة بناء وتمهيد النواة الجديدة.
4. قم بتشغيل ما يلي للتحقق من أدوات التتبع المتاحة:

   cat /sys/kernel/tracing/available_tracers
   

5. قم بتأكيد الأمر بإرجاع function ، irqsoff ، و preemptoff ، و preemptirqsoff .
6. قم بتشغيل ما يلي للتأكد من عمل ftrace الديناميكي:

   cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>
   

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

يعد ملف تعريف الوظيفة هو الخيار الأفضل لمشكلات الأداء وغالبًا ما يستخدم لمعرفة مكان استدعاء الوظيفة.

عرض المشكلة: صورة HDR + عدسة الكاميرا الدوارة

في هذه المشكلة، يؤدي استخدام Pixel XL لالتقاط صورة HDR+ ثم تدوير عدسة الكاميرا على الفور إلى حدوث خلل في كل مرة. استخدمنا ملف تعريف الوظيفة لتصحيح المشكلة في أقل من ساعة واحدة. لمتابعة المثال، قم بتنزيل ملف Zip الخاص بالآثار (الذي يتضمن أيضًا آثارًا أخرى مشار إليها في هذا القسم)، وقم بفك ضغط الملف، وافتح ملف Trace_30898724.html في متصفحك.

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

في هذه المرحلة نحتاج إلى معرفة من يتصل بـ ion_client_destroy ، لذا فقد حان الوقت لاستخدام ملف تعريف الوظيفة:

1. نظرًا لأن المترجم يعيد تسمية الوظائف أحيانًا، تأكد من وجود ion_client_destroy باستخدام:

   cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
   

2. بعد التأكد من وجوده، استخدمه كفلتر ftrace:

   echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
   

3. قم بتشغيل ملف تعريف الوظيفة:

   echo function > /sys/kernel/tracing/current_tracer
   

4. قم بتشغيل تتبعات المكدس عندما يتم استدعاء وظيفة التصفية:

   echo func_stack_trace > /sys/kernel/tracing/trace_options
   

5. زيادة حجم المخزن المؤقت:

   echo 64000 > /sys/kernel/tracing/buffer_size_kb
   

6. قم بتشغيل التتبع:

   echo 1 > /sys/kernel/tracing/trace_on
   

7. قم بإجراء الاختبار واحصل على التتبع:

   cat /sys/kernel/tracing/trace > /data/local/tmp/trace
   

8. اعرض التتبع لرؤية الكثير والكثير من آثار المكدس:

       cameraserver-643   [003] ...1    94.192991: ion_client_destroy <-ion_release
       cameraserver-643   [003] ...1    94.192997: <stack trace>
    => ftrace_ops_no_ops
    => ftrace_graph_call
    => ion_client_destroy
    => ion_release
    => __fput
    => ____fput
    => task_work_run
    => do_notify_resume
    => work_pending
    

بناءً على فحص برنامج التشغيل الأيوني، يمكننا أن نرى أن ion_client_destroy يتم إرسال بريد عشوائي إليه بواسطة وظيفة مساحة المستخدم التي تغلق fd إلى /dev/ion ، وليس برنامج تشغيل kernel عشوائي. من خلال البحث في قاعدة بيانات Android عن \"/dev/ion\" ، نجد العديد من برامج تشغيل البائعين تفعل نفس الشيء مثل برنامج التشغيل Hexagon وفتح/إغلاق /dev/ion (إنشاء وتدمير عميل أيون جديد) في كل مرة يحتاجون فيها إلى برنامج تشغيل. تخصيص أيون جديد أدى تغيير هذه العناصر لاستخدام عميل أيون واحد طوال مدة العملية إلى إصلاح الخلل.

---

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

باستخدام قفلستات

في بعض الأحيان، لا يكون ftrace كافيًا وتحتاج حقًا إلى تصحيح ما يبدو أنه تنافس على قفل kernel. هناك خيار آخر للنواة يستحق التجربة: CONFIG_LOCK_STAT . يعد هذا هو الملاذ الأخير لأنه من الصعب للغاية العمل على أجهزة Android لأنه يؤدي إلى تضخيم حجم النواة بما يتجاوز ما تستطيع معظم الأجهزة التعامل معه.

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

عرض المشكلة: توقف في SCHED_FIFO عندما تكون النوى عند الحد الأقصى للتحميل مع غير SCHED_FIFO

في هذه المشكلة، توقف مؤشر ترابط SCHED_FIFO عندما كانت جميع النوى في أقصى تحميل مع مؤشرات ترابط غير SCHED_FIFO. كانت لدينا آثار تظهر تنافسًا كبيرًا على القفل على fd في تطبيقات الواقع الافتراضي، ولكن لم نتمكن من التعرف بسهولة على fd قيد الاستخدام. لمتابعة المثال، قم بتنزيل ملف الآثار المضغوط (الذي يتضمن أيضًا آثارًا أخرى مشار إليها في هذا القسم)، وقم بفك ضغط الملف، وافتح ملف Trace_30905547.html في متصفحك.

لقد افترضنا أن ftrace نفسه كان مصدر التنافس على القفل، عندما يبدأ الخيط ذو الأولوية المنخفضة في الكتابة إلى أنبوب ftrace ثم يتم استباقه قبل أن يتمكن من تحرير القفل. هذا هو السيناريو الأسوأ الذي تفاقم بسبب مزيج من سلاسل الرسائل ذات الأولوية المنخفضة للغاية التي تكتب إلى علامة ftrace جنبًا إلى جنب مع بعض سلاسل الرسائل ذات الأولوية الأعلى التي تدور على وحدات المعالجة المركزية (CPUs) لمحاكاة جهاز محمل بالكامل.

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

---

إذا كان بإمكانك تشغيل النواة باستخدام خيار التكوين، فإن تتبع القفل يشبه ftrace:

1. تمكين التتبع:

   echo 1 > /proc/sys/kernel/lock_stat
   

2. قم بإجراء الاختبار الخاص بك.
3. تعطيل التتبع:

   echo 0 > /proc/sys/kernel/lock_stat
   

4. تفريغ التتبع الخاص بك:

   cat /proc/lock_stat > /data/local/tmp/lock_stat
   

للمساعدة في تفسير المخرجات الناتجة، راجع وثائق lockstat على <kernel>/Documentation/locking/lockstat.txt .

استخدام نقاط تتبع البائع

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

  { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, {
        { OPT,      "events/mdss/enable" },
        { OPT,      "events/sde/enable" },
        { OPT,      "events/mali_systrace/enable" },
    } },

نقاط التتبع قابلة للتوسيع بواسطة خدمة HAL مما يسمح لك بإضافة نقاط/فئات تتبع خاصة بالجهاز. تم دمج نقاط التتبع مع perfetto، وatrace/systrace، وتطبيق تتبع النظام على الجهاز.

واجهات برمجة التطبيقات (APIs) لتنفيذ نقاط التتبع/الفئات هي:

• تنشئ listCategories() (فئات vec<TracingCategory>);
• يُنشئ تمكين الفئات (فئات vec<string>) (حالة الحالة) ؛
• يُنشئ DisableAllCategories () (حالة الحالة) ؛

لمزيد من المعلومات، راجع تعريف HAL ​​والتنفيذ الافتراضي في AOSP :