החל מ-27 במרץ 2025, מומלץ להשתמש ב-android-latest-release במקום ב-aosp-main כדי ליצור תרומות ל-AOSP. מידע נוסף זמין במאמר שינויים ב-AOSP.

דף זה תורגם על ידי Cloud Translation API.

שימוש ב-ftrace
קל לארגן דפים בעזרת אוספים אפשר לשמור ולסווג תוכן על סמך ההעדפות שלך.

ftrace הוא כלי לניפוי באגים שעוזר להבין מה קורה בתוך ליבה של Linux. בקטעים הבאים מפורטות הפונקציות הבסיסיות של ftrace, השימוש ב-ftrace עם atrace (שמתעדים אירועים בליבה) ו-ftrace דינמי.

לפרטים על פונקציונליות מתקדמת של ftrace שלא זמינה ב-systrace, אפשר לעיין במסמכי התיעוד של ftrace בכתובת <kernel tree>/Documentation/trace/ftrace.txt.

תיעוד אירועים בליבה באמצעות atrace

הכלי atrace‏ (frameworks/native/cmds/atrace) משתמש ב-ftrace כדי לתעד אירועים בליבה. בתורו, systrace.py (או run_systrace.py בגרסאות מאוחרות יותר של Catapult) משתמש ב-adb כדי להריץ את atrace במכשיר. הפקודה atrace מבצעת את הפעולות הבאות:

הגדרת מעקב במצב משתמש על ידי הגדרת מאפיין (debug.atrace.tags.enableflags).
הפעלת הפונקציונליות הרצויה של ftrace על ידי כתיבת צמתים מתאימים של ftrace sysfs. עם זאת, מכיוון ש-ftrace תומך בתכונות נוספות, תוכלו להגדיר בעצמכם כמה צמתים של sysfs ואז להשתמש ב-atrace.

מלבד מעקב בזמן האתחול, כדאי להשתמש ב-atrace כדי להגדיר את המאפיין לערך המתאים. המאפיין הוא מסכת ביט, ואין דרך טובה לקבוע את הערכים הנכונים מלבד בדיקה של הכותרת המתאימה (שיכולה להשתנות בין גרסאות Android).

הפעלת אירועי ftrace

צמתים של sysfs ב-ftrace נמצאים ב-/sys/kernel/tracing, ואירועי trace מחולקים לקטגוריות ב-/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. האפשרות הזו שימושית כשרוצים מעקב רק אחרי הליבה (או אם הקדשתם זמן לכתיבת נכס המעקב במצב משתמש ביד). כדי להריץ רק את ftrace:

מגדירים את גודל המאגר לערך גדול מספיק למעקב:
```
echo 96000 > /sys/kernel/tracing/buffer_size_kb
```

מפעילים את המעקב:

echo 1 > /sys/kernel/tracing/tracing_on

מריצים את הבדיקה ומשביתים את המעקב:
```
echo 0 > /sys/kernel/tracing/tracing_on
```

יצירת גרסת dump של המעקב:

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.

כדי למצוא אירוע ftrace נתון מאירוע Catapult:

פותחים את יומן ה-ftrace הגולמי. בגרסת systrace האחרונות, הטרייסים דחוסים כברירת מחדל:
- אם תיעדו את ה-systrace באמצעות --no-compress, הוא יופיע בקובץ ה-HTML בקטע שמתחיל ב-BEGIN TRACE.
- אם לא, מריצים את html2trace מהעץ של Catapult (tracing/bin/html2trace) כדי לבטל את דחיסת המעקב.
מחפשים את חותמת הזמן היחסית בתצוגה החזותית של Catapult.
מחפשים שורה בתחילת המעקב שמכילה את הערך 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 הרגילים לא מספיקים, יש לכם אפשרות אחרונה: ftrace דינמי. ftrace דינמי כרוך בכתיבת מחדש של קוד הליבה אחרי האתחול, ולכן הוא לא זמין בליבות ייצור מסיבות אבטחה. עם זאת, כל באג קשה שקשור לביצועים בשנים 2015 ו-2016 זוהה בסופו של דבר באמצעות ftrace דינמי. היא שימושית במיוחד לניפוי באגים של זמן השהיה ללא הפסקה, כי אפשר לקבל מעקב סטאק בליבה בכל פעם שמפעילים את הפונקציה שמפעילה את זמן השהיה ללא הפסקה. אפשר גם לנפות באגים בקטעים שבהם השבתתם את ההפרעות וההקדמות, וזה יכול להיות מאוד שימושי כדי לאתר בעיות.

כדי להפעיל את ftrace הדינמי, עורכים את קובץ ה-defconfig של הליבה:

מסירים את CONFIG_STRICT_MEMORY_RWX (אם הוא קיים). אם אתם משתמשים בגרסה 3.18 ואילך וב-arm64, הוא לא מופיע.
מוסיפים את הערכים הבאים: CONFIG_DYNAMIC_FTRACE=y,‏ CONFIG_FUNCTION_TRACER=y,‏ CONFIG_IRQSOFF_TRACER=y,‏ CONFIG_FUNCTION_PROFILER=y ו-CONFIG_PREEMPT_TRACER=y
יוצרים מחדש את הליבה החדשה ומפעילים אותה.
מריצים את הפקודה הבאה כדי לבדוק אילו גששים זמינים:
```
cat /sys/kernel/tracing/available_tracers
```
מוודאים שהפקודה מחזירה את הערכים function,‏ irqsoff,‏ preemptoff ו-preemptirqsoff.
מריצים את הפקודה הבאה כדי לוודא ש-ftrace הדינמי פועל:
```
cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>
```

אחרי השלמת השלבים האלה, תוכלו להשתמש ב-ftrace דינמי, ב-profiler של פונקציות, ב-profiler של irqsoff וב-profiler של preemptoff. מומלץ מאוד לקרוא את המסמכים של ftrace בנושאים האלה לפני שמשתמשים בהם, כי הם חזקים אבל מורכבים. האפשרויות irqsoff ו-preemptoff שימושות בעיקר כדי לוודא שמנהלי ההתקנים משאירים את ההפרעות או את הפסקת הפעילות מושבתה למשך זמן רב מדי.

פרופיל הפונקציה הוא האפשרות הטובה ביותר לבעיות בביצועים, והוא משמש לרוב כדי לברר איפה מתבצעת קריאה לפונקציה.

הצגת הבעיה: תמונת HDR + עינית מסתובבת

בבעיה הזו, שימוש ב-Pixel XL לצילום תמונה ב-HDR+‎ ולאחר מכן מיד ביטול הכיוון של העינית גרם לתנודות בכל פעם. הבעיה נפתרה תוך פחות משעה בעזרת הכלי לניתוח פרופיל הפונקציה. כדי להמשיך עם הדוגמה, מורידים את קובץ ה-zip של הטראסים (שכולל גם טראסים אחרים שצוינו בקטע הזה), פותחים את הקובץ trace_30898724.html בדפדפן.

ב-trace מוצגים כמה חוטים בתהליך של שרת המצלמה שנחסמו במצב שינה ללא הפסקה ב-ion_client_destroy. זו פונקציה יקרה, אבל צריך להפעיל אותה לעיתים רחוקות מאוד כי לקוחות ion צריכים לכלול הקצאות רבות. בהתחלה, האשמה נפלה על הקוד של Hexagon ב-Halide, שהיה אכן אחד הגורמים לבעיה (הוא יצר לקוח חדש לכל הקצאה של יון והשמיד את הלקוח הזה כשהקצאה השתחררה, וזה היה יקר מדי). המעבר ללקוח ion יחיד לכל ההקצאות של Hexagon שיפר את המצב, אבל הבעיה של התנודות לא נפתרה.

בשלב הזה אנחנו צריכים לדעת מי קורא לפונקציה ion_client_destroy, ולכן הגיע הזמן להשתמש בפרופילר הפונקציות:

לפעמים המהדרר משנה את השם של הפונקציות, לכן צריך לוודא שהפונקציה ion_client_destroy קיימת באמצעות:
```
cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
```
אחרי שמוודאים שהוא קיים, משתמשים בו כמסנן ftrace:
```
echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
```
מפעילים את הכלי לניתוח פרופיל הפונקציה:
```
echo function > /sys/kernel/tracing/current_tracer
```
מפעילים את מעקב הסטאק בכל פעם שמפעילים פונקציית מסנן:
```
echo func_stack_trace > /sys/kernel/tracing/trace_options
```

הגדלת גודל המאגר הזמני:

echo 64000 > /sys/kernel/tracing/buffer_size_kb

מפעילים את המעקב:
```
echo 1 > /sys/kernel/tracing/trace_on
```
מריצים את הבדיקה ומקבלים את המעקב:
```
cat /sys/kernel/tracing/trace > /data/local/tmp/trace
```

אפשר להציג את המעקב כדי לראות המון המון מעקבים אחרי סטאק:

    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, אפשר לראות ש-ion_client_destroy מקבל ספאם מפונקציה במרחב המשתמש שסוגרת fd ל-/dev/ion, ולא ממנהל ליבה אקראי. חיפוש \"/dev/ion\" בקוד של Android מראה שיש כמה מנהלי התקנים של ספקים שמבצעים את אותה פעולה כמו מנהל ההתקנים של Hexagon, ופותחים/סוגרים את /dev/ion (יוצרים ומוחקים לקוח ion חדש) בכל פעם שהם צריכים הקצאה חדשה של ion. שינוי הקוד כך שישתמש בלקוח ion יחיד לכל משך החיים של התהליך תיקן את הבאג.

אם הנתונים מכלי הניתוח של פונקציות לא ספציפיים מספיק, אפשר לשלב נקודות מעקב של ftrace עם כלי הניתוח של פונקציות. אפשר להפעיל אירועי ftrace באותו אופן שבו מפעילים אותם בדרך כלל, והם ימוקמו בין נקודות המעקב. האפשרות הזו שימושית אם יש מדי פעם השהיה ארוכה ואינטרומבלית בפונקציה ספציפית שרוצים לנפות באגים: מגדירים את המסנן ftrace לפונקציה הרצויה, מפעילים נקודות מעקב ומבצעים מעקב. אפשר לנתח את המעקב שנוצר באמצעות trace2html, למצוא את האירוע הרצוי ואז לקבל את מעקב ה-stack הקרוב במעקב הגולמי.

שימוש ב-lockstat

לפעמים, ftrace לא מספיק וצריכים לנפות באגים במה שנראה כתחרות על נעילת הליבה. יש אפשרות נוספת של ליבה ששווה לנסות: CONFIG_LOCK_STAT. זוהי אפשרות אחרונה כי קשה מאוד להפעיל אותה במכשירי Android, כי היא מגדילה את גודל הליבה מעבר למה שרוב המכשירים יכולים להתמודד איתו.

עם זאת, lockstat משתמש בתשתית הנעילה של ניפוי הבאגים, ששימושית לאפליקציות רבות אחרות. כל מי שעובד על הפעלת המכשיר צריך למצוא דרך להפעיל את האפשרות הזו בכל מכשיר, כי יהיה זמן שבו תגידו "אם רק הייתי יכול להפעיל את LOCK_STAT, הייתי יכול לאשר או להפריך את הבעיה הזו תוך חמש דקות במקום חמש ימים".

הצגת הבעיה: Stall in SCHED_FIFO when cores at max load with non-SCHED_FIFO

בבעיה הזו, השרשור SCHED_FIFO נעצר כשכל הליבות היו בעומס מרבי עם שרשור שאינו SCHED_FIFO. היו לנו עקבות שמראים תחרות משמעותית על נעילת fd באפליקציות VR, אבל לא הצלחנו לזהות בקלות את ה-fd שבשימוש. כדי להמשיך עם הדוגמה, מורידים את קובץ ה-zip של הטראסים (שכולל גם טראסים אחרים שצוינו בקטע הזה), פותחים את הקובץ trace_30905547.html בדפדפן.

הנחנו ש-ftrace עצמו הוא המקור לעימות על נעילת הנעילה, כששרשור בעל תעדוף נמוך מתחיל לכתוב לצינור ftrace ואז מבוטל לפני שהוא יכול לשחרר את הנעילה. זהו תרחיש מקרה הגרוע ביותר, שהוחמר על ידי שילוב של חוטים בעדיפות נמוכה במיוחד שכותבים לסמן ftrace, יחד עם כמה חוטים בעדיפות גבוהה יותר שמסתובבים במעבדים כדי לדמות מכשיר טעון במלואו.

מאחר שלא הצלחנו להשתמש ב-ftrace לניפוי באגים, הפעלנו את LOCK_STAT ואז השבתנו את כל מעקב הנתונים האחר מהאפליקציה. התוצאות הראו שהמתיחה על הנעילה הייתה למעשה מ-ftrace, כי אף אחת מהמתיחות לא הופיעה במעקב הנעילה כש-ftrace לא פועל.

אם אפשר לאתחל את הליבה עם אפשרות התצורה, מעקב אחר נעילת הקבצים דומה ל-ftrace:

מפעילים את המעקב:
```
echo 1 > /proc/sys/kernel/lock_stat
```
מריצים את הבדיקה.
משביתים את המעקב:
```
echo 0 > /proc/sys/kernel/lock_stat
```
מעבירים את המעקב למצב גרסת דמפ:
```
cat /proc/lock_stat > /data/local/tmp/lock_stat
```

במסמכי העזרה של lockstat ב-<kernel>/Documentation/locking/lockstat.txt מוסבר איך לפרש את הפלט שנוצר.

שימוש בנקודות מעקב של ספקים

קודם כול צריך להשתמש בנקודות מעקב (tracepoints) ב-upstream, אבל לפעמים צריך להשתמש בנקודות מעקב של ספקים:

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

אפשר להרחיב את נקודות המעקב באמצעות שירות HAL, וכך להוסיף נקודות מעקב או קטגוריות ספציפיות למכשיר. נקודות המעקב משולבות עם perfetto,‏ atrace/systrace ואפליקציית המעקב אחרי המערכת במכשיר.

ממשקי ה-API להטמעת נקודות מעקב או קטגוריות הם:

הפונקציה listCategories() יוצרת (vec<TracingCategory> categories);
הפונקציה enableCategories(vec<string> categories) יוצרת (Status status);
הפונקציה disableAllCategories() יוצרת (Status status);

מידע נוסף זמין בהגדרה של HAL ובהטמעת ברירת המחדל ב-AOSP:

שימוש ב-ftrace קל לארגן דפים בעזרת אוספים אפשר לשמור ולסווג תוכן על סמך ההעדפות שלך.