ftrace verwenden

ftrace ist ein Debugging-Tool, mit dem Sie verstehen können, was im Inneren Linux-Kernel. In den folgenden Abschnitten werden die grundlegenden ftrace-Funktionen beschrieben, ftrace Verwendung mit atrace (erfasst Kernel-Ereignisse) und dynamischem ftrace.

Einzelheiten zu den erweiterten ftrace-Funktionen, die nicht verfügbar sind unter finden Sie in der ftrace-Dokumentation unter <kernel tree>/Documentation/trace/ftrace.txt

Kernel-Ereignisse mit atrace erfassen

atrace (frameworks/native/cmds/atrace) verwendet ftrace zum Erfassen Kernel-Ereignisse. systrace.py (oder in neueren Versionen von run_systrace.py ) Catapult) verwendet ADB. um auf dem Gerät ein Trace auszuführen. atrace:

  • Richtet das Tracing im Nutzermodus durch Festlegen einer Eigenschaft ein. (debug.atrace.tags.enableflags)
  • Aktiviert die gewünschte ftrace-Funktionalität, indem in den entsprechenden ftrace sysfs-Knoten. Da ftrace jedoch mehr Funktionen unterstützt, können Sie und verwenden dann atrace.

Mit Ausnahme des Tracings beim Booten können Sie mit atrace den Parameter auf den entsprechenden Wert. Die Eigenschaft ist eine Bitmaske und es gibt keine gute Möglichkeit, die richtigen Werte zu ermitteln, als den entsprechenden Header zu betrachten Das kann sich je nach Android-Version ändern.

ftrace-Ereignisse aktivieren

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

So aktivieren Sie Ereignisse für einzelne Kategorien: 

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

So aktivieren Sie Ereignisse für einzelne Ereignisse: 

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

Wenn durch das Schreiben in Sysfs-Knoten zusätzliche Ereignisse aktiviert wurden, nicht durch atrace zurückgesetzt werden. Ein gemeinsames Muster für die Bereitstellung von Qualcomm-Geräten ist die Aktivierung von kgsl (GPU) und mdss (Pipeline anzeigen) und verwenden Sie dann atrace oder 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

Sie können ftrace auch ohne "atrace" oder "systrace" verwenden, nützlich, wenn Sie Nur-Kernel-Traces benötigen (oder wenn Sie sich die Zeit genommen haben, die Tracing-Eigenschaft im Nutzermodus manuell. So führen Sie nur ftrace aus:

  1. Legen Sie die Puffergröße auf einen Wert fest, der groß genug für den Trace ist: 
    echo 96000 > /sys/kernel/tracing/buffer_size_kb
  2. Tracing aktivieren: 
    echo 1 > /sys/kernel/tracing/tracing_on
  3. Führen Sie den Test aus und deaktivieren Sie dann das Tracing: 
    echo 0 > /sys/kernel/tracing/tracing_on
  4. Speichern Sie den Trace: 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace_output

Trace_output liefert den Trace in Textform. Zur Visualisierung mit Katapult, schnapp dir das Katapult Repository von GitHub und führen Sie „trace2html“ aus:

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

Standardmäßig wird trace_file.html im selben -Verzeichnis.

Ereignisse korrelieren

Ein Blick auf die Catapult-Visualisierung und den ftrace gleichzeitig protokollieren; z. B. einige ftrace-Ereignisse (insbesondere anbieterspezifische werden von Catapult nicht visualisiert. Die Zeitstempel von Catapult relativ zum ersten Ereignis im Trace oder zu einem bestimmten Zeitstempel die von atrace ausgegeben werden, während die ftrace-Rohzeitstempel auf einem bestimmten als absolute Taktquelle im Linux-Kernel.

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

  1. Öffnen Sie das ftrace-Rohprotokoll. Traces in neueren Versionen von systrace sind standardmäßig komprimiert: <ph type="x-smartling-placeholder">
      </ph>
    • Wenn Sie Ihr Systrace mit --no-compress erfasst haben, befindet sich dies in der HTML-Datei in dem Abschnitt, der mit BEGIN TRACE beginnt.
    • Falls nicht, führen Sie html2trace über die Katapult Baum (tracing/bin/html2trace), um den Trace zu dekomprimieren.
  2. Suchen Sie den relativen Zeitstempel in der Catapult-Visualisierung.
  3. Suchen Sie eine Zeile am Anfang des Trace, die enthält tracing_mark_sync Sie sollte in etwa so aussehen: 
    <5134>-5134  (-----) [003] ...1    68.104349: tracing_mark_write: trace_event_clock_sync: parent_ts=68.104286

    Wenn diese Zeile nicht existiert oder Sie ftrace ohne atrace verwendet haben, Die Zeitangaben sind relativ zum ersten Ereignis im ftrace-Log.
    1. Addieren Sie den relativen Zeitstempel (in Millisekunden) zum Wert in parent_ts (in Sekunden).
    2. Suchen Sie nach dem neuen Zeitstempel.

Mit diesen Schritten sollten Sie die Veranstaltung (oder zumindest sehr nah am Veranstaltungsort) erreichen.

Dynamisches ftrace verwenden

Wenn Systrace und Standard-ftrace nicht ausreichend sind, gibt es noch ein letztes verfügbarer Recourse: dynamisches ftrace. Beim dynamischen ftrace wird Umschreibung des Kernel-Codes nach dem Booten. Daher ist er in der Produktion nicht verfügbar. aus Sicherheitsgründen verwenden. Aber jeder schwierige Leistungsfehler in einem 2015 und 2016 war die Ursache mithilfe von dynamischem ftrace. Besonders wichtig ist es, sind leistungsstarke Funktionen zum Debuggen von unterbrechungsfreien Ruhezustand, da Sie einen Stacktrace erhalten im Kernel ein, wenn Sie die Funktion aktivieren, die einen unterbrechungsfreien Ruhemodus auslöst. Sie können auch Fehler in Bereichen beheben, in denen Unterbrechungen und Präemptionen deaktiviert sind. sehr nützlich sein, um Probleme nachzuweisen.

Bearbeiten Sie die defconfig Ihres Kernels, um dynamisches ftrace zu aktivieren:

  1. Entfernen Sie CONFIG_STRICT_MEMORY_RWX, sofern vorhanden. Wenn Sie Version 3.18 oder neuer und arm64 nicht vorhanden ist.
  2. 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
  3. Erstellen Sie den neuen Kernel neu und starten Sie ihn neu.
  4. Führen Sie den folgenden Befehl aus, um nach verfügbaren Tracern zu suchen: 
    cat /sys/kernel/tracing/available_tracers
  5. Prüfen Sie, ob der Befehl function, irqsoff, preemptoff und preemptirqsoff.
  6. Führen Sie den folgenden Befehl aus, um sicherzustellen, dass das dynamische ftrace funktioniert: 
    cat /sys/kernel/tracing/available_filter_functions | grep <a function you care about>

Nachdem Sie diese Schritte ausgeführt haben, haben Sie das dynamische ftrace den irqsoff-Profiler und den präemptiven Profiler. Wir empfehlen, dass Sie vor der Verwendung der ftrace-Dokumentation zu diesen Themen da sie leistungsstark, aber komplex sind. "irqsoff" und "keine vorzeitige Verbindung" sind nützlich, um zu bestätigen, dass Treiber Unterbrechungen oder vorzeitige Beendigungen verlassen. zu lange deaktiviert.

Der Funktion Profiler ist die beste Option bei Leistungsproblemen und um herauszufinden, wo eine Funktion aufgerufen wird.

Bei dieser Ausgabe nimmt man mit einem Pixel XL ein HDR+ Foto auf und versucht dann sofort, Drehen des Suchers verursachte jedes Mal eine Verzögerung. Wir haben den Funktion Profiler 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 Traces enthält, auf die in diesem Abschnitt verwiesen wird), entpacken Sie die Datei und öffnen Sie das Trace_30898724.html in Ihrem Browser.

Der Trace zeigt, dass mehrere Threads im Kameraserverprozess blockiert sind in unterbrechungsfreier Schlaf auf ion_client_destroy. Das ist ein teurer -Funktion, sollte jedoch nur selten aufgerufen werden, da Ionen-Clients umfassen viele Zuweisungen. Am Anfang lag die Schuld auf dem Hexadezimalcode Halide, einer der Täter. und diesen Client zerstört haben, als die Zuweisung freigegeben wurde. viel zu teuer war). Wechsel zu einem einzelnen Ionen-Client für alle Hexagon-Modelle die Zuweisungen verbesserten die Situation, aber die Verzögerung wurde nicht behoben.

Jetzt müssen wir wissen, wer ion_client_destroy anruft, Daher ist es an der Zeit, den Funktion Profiler zu verwenden:

  1. Da Funktionen manchmal vom Compiler umbenannt werden, bestätigen Sie ion_client_destroy lässt sich über Folgendes aufrufen: 
    cat /sys/kernel/tracing/available_filter_functions | grep ion_client_destroy
  2. Nachdem Sie überprüft haben, ob er vorhanden ist, verwenden Sie ihn als ftrace-Filter: 
    echo ion_client_destroy > /sys/kernel/tracing/set_ftrace_filter
  3. Aktivieren Sie den Funktion Profiler: 
    echo function > /sys/kernel/tracing/current_tracer
  4. Aktivieren Sie bei jedem Aufruf einer Filterfunktion Stacktraces: 
    echo func_stack_trace > /sys/kernel/tracing/trace_options
  5. Erhöhen Sie die Puffergröße: 
    echo 64000 > /sys/kernel/tracing/buffer_size_kb
  6. Aktivieren Sie das Tracing: 
    echo 1 > /sys/kernel/tracing/trace_on
  7. Führen Sie den Test aus und rufen Sie den Trace ab: 
    cat /sys/kernel/tracing/trace > /data/local/tmp/trace
  8. Sehen Sie sich den Trace an, um viele Stacktraces 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

Eine Überprüfung des Ionentreibers hat ergeben, ion_client_destroy wird von einer Userspace-Funktion mit Spam überflutet, die geschlossen wird eine fd an /dev/ion und nicht an einen zufälligen Kernel-Treiber. Im Bereich Android-Codebasis für \"/dev/ion\" – wir finden verschiedene Anbietertreiber genau wie der Hexagon-Treiber /dev/ion (Erstellen und Löschen eines neuen Ionen-Clients) eine neue Ionenzuweisung erforderlich ist. Ändern zu verwenden einen einzelnen Ionen-Client während der gesamten Lebensdauer des Prozesses genutzt haben

Wenn die Daten aus dem Funktion Profiler nicht spezifisch genug sind, können Sie ftrace-Tracepoints mit dem Funktionsprofiler erstellen. ftrace-Ereignisse können in und werden mit Ihrem Trace verschränkt. Das ist gut, wenn du hin und wieder lange und unterbrechungsfrei in einer bestimmten die Sie debuggen möchten: Legen Sie den ftrace-Filter auf die gewünschte Funktion fest. Aktivieren Sie Tracepoints, machen Sie einen Trace. Sie können den resultierenden Trace mit trace2html, suche das gewünschte Ereignis und rufe dann Stacktraces in der Nähe ab im Roh-Trace.

Sperrstatistik verwenden

Manchmal reicht ftrace nicht aus und Sie müssen das Debugging Kernel-Sperrkonflikt vorliegt. Es gibt noch eine weitere Kernel-Option, die Sie ausprobieren sollten: CONFIG_LOCK_STAT Dies ist die letzte Option, mit Android-Geräten zu arbeiten, da die Größe der die die meisten Geräte verarbeiten können.

„lockstat“ verwendet jedoch das Debugging-Tool die für viele andere Anwendungen nützlich ist. Alle Die Arbeit am Gerät sollte eine Möglichkeit finden, diese Option zum Laufen zu bringen. auf jedem Gerät einrichten, weil es einen Zeitpunkt geben wird, an dem „Wenn ich nur LOCK_STAT aktivieren könnte, könnte ich das bestätigen oder widerlegen das Problem in fünf Minuten statt fünf Tagen zu lösen.“

Bei diesem Problem wurde der SCHED_FIFO-Thread angehalten, als alle Kerne das Maximum erreicht hatten. mit Nicht-SCHED_FIFO-Threads laden. Es gab Traces, die eine signifikante Sperre zeigten in VR-Apps konfrontiert waren, konnten wir die verwendete FD jedoch nicht ohne Weiteres identifizieren. Um dem Beispiel zu folgen, laden Sie die ZIP-Datei herunter Datei mit Traces, die auch andere Traces enthält, auf die in diesem ), entpacken Sie die Datei und öffnen Sie die Datei "trace_30905547.html" in Ihrem Browser.

Wir stellten die Hypothese auf, dass ftrace selbst der Ursprung von Sperrenkonflikten war, wenn ein einen Thread mit niedriger Priorität in die ftrace-Pipe schreiben würde vorzeitig beendet, bevor die Sperre aufgehoben werden konnte. Dies ist ein Worst-Case-Szenario, durch eine Mischung aus Threads mit extrem niedriger Priorität, die ftrace-Markierung sowie einige Threads mit höherer Priorität, die auf CPUs laufen, vollständig geladenes Gerät zu simulieren.

Da ftrace nicht zur Fehlerbehebung verwendet werden konnte, funktioniert LOCK_STAT. und deaktiviert alle anderen Tracing-Elemente in der App. In den Ergebnissen wurde das Schloss angezeigt stammte tatsächlich von ftrace, da keiner der Konflikte in Sperr-Trace, als ftrace nicht ausgeführt wurde.

Wenn Sie einen Kernel mit der Konfigurationsoption starten können, ähnelt das Sperr-Tracing ftrace:

  1. Tracing aktivieren: 
    echo 1 > /proc/sys/kernel/lock_stat
  2. Führen Sie den Test durch.
  3. Tracing deaktivieren: 
    echo 0 > /proc/sys/kernel/lock_stat
  4. Speichern Sie den Trace: 
    cat /proc/lock_stat > /data/local/tmp/lock_stat

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

Anbieter-Trace-Punkte verwenden

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

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

Tracepoints können durch den HAL-Dienst erweitert werden, sodass Sie gerätespezifische Traces hinzufügen können Punkte/Kategorien. Tracepoints sind in Perfetto, atrace/systrace und in das On-Device-System integriert. Tracing-App.

Folgende APIs können zur Implementierung von Tracepoints/Kategorien verwendet werden:

  • listCategories()generates (vec<TracingCategory>-Kategorien);
  • enabledKategorien(vec<string> Kategorien) generiert (Statusstatus);
  • disableAllCategories()generated (Status status);
Weitere Informationen finden Sie in der HAL-Definition und Standardimplementierung in AOSP: