Diese Seite wurde von der Cloud Translation API übersetzt.

Mit ftrace

ftrace ist ein Debugging-Tool, um zu verstehen, was im Linux-Kernel vor sich geht. In den folgenden Abschnitten werden die grundlegende Ftrace-Funktionalität, die Ftrace-Verwendung mit atrace (das Kernel-Ereignisse erfasst) und das dynamische Ftrace detailliert beschrieben.

Einzelheiten zur erweiterten Ftrace-Funktionalität, die von systrace nicht verfügbar ist, finden Sie in der Ftrace-Dokumentation unter <kernel tree>/Documentation/trace/ftrace.txt .

Erfassen von Kernel-Ereignissen mit atrace

atrace ( frameworks/native/cmds/atrace ) verwendet ftrace, um Kernel-Ereignisse zu erfassen. Im Gegenzug verwendet systrace.py (oder run_systrace.py in späteren Versionen von Catapult ) adb, um atrace auf dem Gerät auszuführen. atrace führt Folgendes aus:

Richtet die Ablaufverfolgung im Benutzermodus ein, indem eine Eigenschaft festgelegt wird ( debug.atrace.tags.enableflags ).
Aktiviert die gewünschte Ftrace-Funktionalität durch Schreiben in die entsprechenden Ftrace-SYSFS-Knoten. Da ftrace jedoch mehr Funktionen unterstützt, können Sie einige SYSFS-Knoten selbst festlegen und dann atrace verwenden.

Mit Ausnahme der Boot-Zeit-Ablaufverfolgung sollten Sie sich auf die Verwendung von atrace verlassen, um die Eigenschaft auf den entsprechenden Wert festzulegen. Die Eigenschaft ist eine Bitmaske und es gibt keine gute Möglichkeit, die richtigen Werte zu ermitteln, außer sich den entsprechenden Header anzusehen (der sich zwischen Android-Versionen ändern kann).

Ftrace-Ereignisse aktivieren

Die ftrace-sysfs-Knoten befinden sich in /sys/kernel/tracing und Trace-Ereignisse sind in /sys/kernel/tracing/events in Kategorien unterteilt.

Um Ereignisse pro Kategorie zu aktivieren, verwenden Sie:

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

Um Ereignisse pro Ereignis zu aktivieren, verwenden Sie:

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

Wenn zusätzliche Ereignisse durch Schreiben auf sysfs-Knoten aktiviert wurden, werden sie von atrace nicht zurückgesetzt. Ein gängiges Muster für die Bereitstellung von Qualcomm-Geräten besteht darin, kgsl (GPU) und mdss -Tracepoints (Display-Pipeline) zu aktivieren und dann atrace oder systrace zu verwenden:

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

Sie können ftrace auch ohne atrace oder systrace verwenden, was nützlich ist, wenn Sie nur Kernel-Traces wünschen (oder wenn Sie sich die Zeit genommen haben, die Trace-Eigenschaft für den Benutzermodus manuell zu schreiben). So führen Sie einfach ftrace aus:

Legen Sie die Puffergröße auf einen Wert fest, der groß genug für Ihren Trace ist:
```
echo 96000 > /sys/kernel/tracing/buffer_size_kb
```

Ablaufverfolgung aktivieren:

echo 1 > /sys/kernel/tracing/tracing_on

Führen Sie Ihren Test aus und deaktivieren Sie dann die Ablaufverfolgung:
```
echo 0 > /sys/kernel/tracing/tracing_on
```

Geben Sie den Trace aus:

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

Der Trace_Output gibt den Trace in Textform aus. Um es mit Catapult zu visualisieren, holen Sie sich das Catapult-Repository von GitHub und führen Sie Trace2html aus:

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

Standardmäßig wird die Datei trace_file.html in dasselbe Verzeichnis geschrieben.

Korrelierende Ereignisse

Es ist oft nützlich, sich gleichzeitig die Catapult-Visualisierung und das Ftrace-Protokoll anzusehen. Beispielsweise werden einige Ftrace-Ereignisse (insbesondere herstellerspezifische) von Catapult nicht visualisiert. Die Zeitstempel von Catapult beziehen sich jedoch entweder auf das erste Ereignis im Trace oder auf einen bestimmten von atrace ausgegebenen Zeitstempel, während die rohen Ftrace-Zeitstempel auf einer bestimmten absoluten Taktquelle im Linux-Kernel basieren.

So finden Sie ein bestimmtes Ftrace-Ereignis aus einem Catapult-Ereignis:

Öffnen Sie das rohe Ftrace-Protokoll. Traces in neueren Versionen von Systrace werden standardmäßig komprimiert:
- Wenn Sie Ihren Systrace mit --no-compress erfasst haben, befindet sich dieser in der HTML-Datei im Abschnitt, der mit BEGIN TRACE beginnt.
- Wenn nicht, führen Sie html2trace aus dem Catapult-Baum aus ( tracing/bin/html2trace ), um den Trace zu dekomprimieren.
Suchen Sie den relativen Zeitstempel in der Catapult-Visualisierung.
Suchen Sie am Anfang der Ablaufverfolgung eine Zeile mit tracing_mark_sync . Es sollte etwa so aussehen:
```
<5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286
```
Wenn diese Zeile nicht vorhanden ist (oder wenn Sie ftrace ohne atrace verwendet haben), sind die Zeitangaben relativ zum ersten Ereignis im ftrace-Protokoll.
1. Addieren Sie den relativen Zeitstempel (in Millisekunden) zum Wert in parent_ts (in Sekunden).
2. Suchen Sie nach dem neuen Zeitstempel.

Diese Schritte sollten Sie an das Ereignis heranführen (oder ihm zumindest sehr nahe kommen).

Verwendung von dynamischem Ftrace

Wenn Systrace und Standard-FTrace nicht ausreichen, gibt es eine letzte Möglichkeit: dynamisches Ftrace . Beim dynamischen Ftrace wird der Kernel-Code nach dem Booten neu geschrieben und ist daher aus Sicherheitsgründen in Produktionskerneln nicht verfügbar. Allerdings wurde jeder einzelne schwerwiegende Leistungsfehler in den Jahren 2015 und 2016 letztendlich mithilfe von dynamischem Ftrace an der Wurzel verursacht. Es ist besonders leistungsstark für das Debuggen unterbrechungsfreier Ruhezustände, da Sie jedes Mal, wenn Sie die Funktion aufrufen, die den unterbrechungsfreien Ruhezustand auslöst, einen Stack-Trace im Kernel abrufen können. Sie können Abschnitte auch mit deaktivierten Interrupts und Preemptions debuggen, was zum Nachweis von Problemen sehr nützlich sein kann.

Um dynamisches Ftrace zu aktivieren, bearbeiten Sie die Defconfig Ihres Kernels:

Entfernen Sie CONFIG_STRICT_MEMORY_RWX (falls vorhanden). Wenn Sie 3.18 oder neuer und arm64 verwenden, ist es nicht vorhanden.
Fügen Sie Folgendes hinzu: CONFIG_DYNAMIC_FTRACE=y, CONFIG_FUNCTION_TRACER=y, CONFIG_IRQSOFF_TRACER=y, CONFIG_FUNCTION_PROFILER=y und CONFIG_PREEMPT_TRACER=y
Erstellen Sie den neuen Kernel neu und starten Sie ihn.
Führen Sie Folgendes aus, um nach verfügbaren Tracern zu suchen:
```
cat /sys/kernel/tracing/available_tracers
```
Bestätigen Sie, dass der Befehl „ function , irqsoff , preemptoff “ und preemptirqsoff zurückgibt.

Führen Sie Folgendes aus, um sicherzustellen, dass der dynamische Ftrace funktioniert:

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

Nach Abschluss dieser Schritte stehen Ihnen Dynamic Ftrace, der Funktionsprofiler, der IRQSOFF-Profiler und der Preemptoff-Profiler zur Verfügung. Wir empfehlen dringend, die Ftrace-Dokumentation zu diesen Themen zu lesen, bevor Sie sie verwenden, da sie leistungsstark, aber komplex sind. irqsoff und preemptoff sind in erster Linie nützlich, um zu bestätigen, dass Treiber möglicherweise Interrupts oder Preemption zu lange deaktiviert lassen.

Der Funktionsprofiler ist die beste Option bei Leistungsproblemen und wird häufig verwendet, um herauszufinden, wo eine Funktion aufgerufen wird.

Problem anzeigen: HDR-Foto + rotierender Sucher

In diesem Fall verursachte die Verwendung eines Pixel XL zum Aufnehmen eines HDR+-Fotos und das anschließende Drehen des Suchers jedes Mal ein Ruckeln. Wir haben den Funktionsprofiler verwendet, um das Problem in weniger als einer Stunde zu beheben. Um dem Beispiel zu folgen, laden Sie die ZIP-Datei mit den Traces herunter (die auch andere in diesem Abschnitt erwähnte Traces enthält), entpacken Sie die Datei und öffnen Sie die Datei „trace_30898724.html“ in Ihrem Browser.

Die Ablaufverfolgung zeigt mehrere Threads im Kameraserverprozess, die auf ion_client_destroy im ununterbrochenen Ruhezustand blockiert sind. Das ist eine teure Funktion, die aber sehr selten aufgerufen werden sollte, da Ion-Clients viele Zuweisungen umfassen sollten. Ursprünglich lag die Schuld beim Hexagon-Code in Halide, der tatsächlich einer der Übeltäter war (er erstellte für jede Ionenzuteilung einen neuen Client und zerstörte diesen Client, als die Zuteilung freigegeben wurde, was viel zu teuer war). Der Wechsel zu einem einzelnen Ionen-Client für alle Hexagon-Zuteilungen verbesserte die Situation, der Fehler wurde jedoch nicht behoben.

An diesem Punkt müssen wir wissen, wer ion_client_destroy aufruft, also ist es an der Zeit, den Funktionsprofiler zu verwenden:

Da Funktionen manchmal vom Compiler umbenannt werden, bestätigen Sie, dass ion_client_destroy vorhanden ist, indem Sie Folgendes verwenden:
```
cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
```
Nachdem Sie bestätigt haben, dass es vorhanden ist, verwenden Sie es als Ftrace-Filter:
```
echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
```

Aktivieren Sie den Funktionsprofiler:

echo function > /sys/kernel/tracing/current_tracer

Aktivieren Sie Stack-Traces, wenn eine Filterfunktion aufgerufen wird:
```
echo func_stack_trace > /sys/kernel/tracing/trace_options
```

Erhöhen Sie die Puffergröße:

echo 64000 > /sys/kernel/tracing/buffer_size_kb

Aktivieren Sie die Ablaufverfolgung:
```
echo 1 > /sys/kernel/tracing/trace_on
```

Führen Sie den Test aus und rufen Sie den Trace ab:

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

Sehen Sie sich den Trace an, um viele, viele Stack-Traces zu sehen:

    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

Basierend auf der Inspektion des Ion-Treibers können wir erkennen, dass ion_client_destroy von einer Userspace-Funktion gespammt wird, die einen fd zu /dev/ion schließt, und nicht von einem zufälligen Kernel-Treiber. Wenn wir die Android-Codebasis nach \"/dev/ion\" durchsuchen, finden wir Treiber verschiedener Hersteller, die das Gleiche tun wie der Hexagon-Treiber und /dev/ion jedes Mal öffnen/schließen (einen neuen Ion-Client erstellen und zerstören), wenn sie einen benötigen neue Ionenzuordnung. Der Fehler wurde behoben, indem man diese so änderte, dass für die gesamte Lebensdauer des Prozesses ein einzelner Ion-Client verwendet wurde .

Wenn die Daten vom Funktionsprofiler nicht spezifisch genug sind, können Sie Ftrace-Tracepoints mit dem Funktionsprofiler kombinieren. Ftrace-Ereignisse können auf genau die gleiche Weise wie gewohnt aktiviert werden und werden mit Ihrem Trace verschachtelt. Das ist großartig, wenn es in einer bestimmten Funktion, die Sie debuggen möchten, gelegentlich zu einem langen, ununterbrochenen Ruhezustand kommt: Stellen Sie den Ftrace-Filter auf die gewünschte Funktion ein, aktivieren Sie Tracepoints, erstellen Sie einen Trace. Sie können den resultierenden Trace mit trace2html analysieren, das gewünschte Ereignis finden und dann benachbarte Stack-Traces im Roh-Trace abrufen.

Lockstat verwenden

Manchmal reicht ftrace nicht aus und Sie müssen wirklich einen scheinbaren Kernel-Lock-Konflikt debuggen. Es gibt noch eine weitere Kernel-Option, die einen Versuch wert ist: CONFIG_LOCK_STAT . Dies ist der letzte Ausweg, da es äußerst schwierig ist, auf Android-Geräten zum Laufen zu kommen, da dadurch die Größe des Kernels über das hinausgeht, was die meisten Geräte bewältigen können.

Lockstat nutzt jedoch die Debug-Sperrinfrastruktur, was für viele andere Anwendungen nützlich ist. Jeder, der an der Geräteaktivierung arbeitet, sollte einen Weg finden, diese Option auf jedem Gerät zum Laufen zu bringen, denn irgendwann denkt man: „Wenn ich nur LOCK_STAT einschalten könnte, könnte ich das Problem in fünf Minuten bestätigen oder widerlegen.“ fünf Tage."

Problem anzeigen: Blockieren im SCHED_FIFO, wenn Kerne mit Nicht-SCHED_FIFO maximal ausgelastet sind

Bei diesem Problem blieb der SCHED_FIFO-Thread stehen, als alle Kerne mit Nicht-SCHED_FIFO-Threads maximal ausgelastet waren. Wir hatten Spuren, die einen erheblichen Sperrkonflikt auf einem FD in VR-Apps zeigten, konnten den verwendeten FD jedoch nicht leicht identifizieren. Um dem Beispiel zu folgen, laden Sie die ZIP-Datei mit den Traces herunter (die auch andere in diesem Abschnitt erwähnte Traces enthält), entpacken Sie die Datei und öffnen Sie die Datei „trace_30905547.html“ in Ihrem Browser.

Wir vermuteten, dass Ftrace selbst die Quelle des Sperrenkonflikts war, wenn ein Thread mit niedriger Priorität mit dem Schreiben in die Ftrace-Pipe begann und dann vorzeitig freigegeben wurde, bevor er die Sperre aufheben konnte. Dies ist ein Worst-Case-Szenario, das durch eine Mischung aus Threads mit extrem niedriger Priorität, die auf den Ftrace-Marker schreiben, und einigen Threads mit höherer Priorität, die auf CPUs laufen, um ein vollständig geladenes Gerät zu simulieren, noch verschärft wurde.

Da wir ftrace nicht zum Debuggen verwenden konnten, haben wir LOCK_STAT zum Laufen gebracht und dann alle anderen Ablaufverfolgungen in der App deaktiviert. Die Ergebnisse zeigten, dass der Sperrenkonflikt tatsächlich von Ftrace stammte, da keiner der Konflikte im Sperren-Trace auftauchte, als Ftrace nicht ausgeführt wurde.

Wenn Sie einen Kernel mit der Konfigurationsoption booten können, ähnelt die Sperrverfolgung der ftrace:

Ablaufverfolgung aktivieren:
```
echo 1 > /proc/sys/kernel/lock_stat
```
Führen Sie Ihren Test durch.
Ablaufverfolgung deaktivieren:
```
echo 0 > /proc/sys/kernel/lock_stat
```

Geben Sie Ihren Trace aus:

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

Hilfe bei der Interpretation der resultierenden Ausgabe finden Sie in der Lockstat-Dokumentation unter <kernel>/Documentation/locking/lockstat.txt .

Verwendung von Anbieter-Tracepoints

Verwenden Sie zuerst Upstream-Tracepoints, aber manchmal müssen Sie auch Anbieter-Tracepoints verwenden:

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

Tracepoints sind durch den HAL-Dienst erweiterbar, sodass Sie gerätespezifische Tracepunkte/Kategorien hinzufügen können. Tracepoints sind in Perfetto, Atrace/Systrace und die System-Tracing-App auf dem Gerät integriert.

Die APIs zum Implementieren von Tracepoints/Kategorien sind:

listCategories()generates (vec<TracingCategory> Kategorien);
enableCategories(vec<string> Kategorien) generiert (Statusstatus);
disableAllCategories() generiert (Status status);

Weitere Informationen finden Sie in der HAL-Definition und Standardimplementierung in AOSP :