Google setzt sich dafür ein, die Rassengerechtigkeit für schwarze Gemeinschaften zu fördern. Siehe wie.
Diese Seite wurde von der Cloud Translation API übersetzt.
Switch to English

Systrace verstehen

systrace ist das wichtigste Tool zur Analyse der Leistung von Android-Geräten. Es ist jedoch wirklich ein Wrapper um andere Tools. Es ist der host-seitige Wrapper um atrace , die geräteseitige ausführbare Datei, die die User-Space- Ablaufverfolgung steuert und ftrace einrichtet , und der primäre Ablaufverfolgungsmechanismus im Linux-Kernel. systrace verwendet atrace, um die Ablaufverfolgung zu aktivieren. Anschließend wird der ftrace-Puffer gelesen und alles in einen eigenständigen HTML-Viewer eingeschlossen. (Während neuere Kernel Linux Enhanced Berkeley Packet Filter (eBPF) unterstützen, bezieht sich die folgende Dokumentation auf den 3.18-Kernel (kein eFPF), da dieser auf dem Pixel / Pixel XL verwendet wurde.)

systrace gehört den Teams von Google Android und Google Chrome und ist im Rahmen des Catapult-Projekts Open Source. Neben systrace enthält Catapult weitere nützliche Dienstprogramme. Beispielsweise verfügt ftrace über mehr Funktionen, als direkt durch systrace oder atrace aktiviert werden können, und enthält einige erweiterte Funktionen, die für das Debuggen von Leistungsproblemen von entscheidender Bedeutung sind. (Diese Funktionen erfordern Root-Zugriff und häufig einen neuen Kernel.)

Laufen systrace

Beginnen Sie beim Debuggen von Jitter auf Pixel / Pixel XL mit dem folgenden Befehl:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

In Kombination mit den zusätzlichen Tracepunkten, die für die GPU und die Anzeige der Pipeline-Aktivität erforderlich sind, können Sie von der Benutzereingabe bis zum auf dem Bildschirm angezeigten Frame verfolgen. Stellen Sie die Puffergröße auf einen großen Wert ein, um zu vermeiden, dass Ereignisse verloren gehen (da einige CPUs ohne großen Puffer nach einem bestimmten Zeitpunkt im Trace keine Ereignisse mehr enthalten).

Beachten Sie beim Durchlaufen von systrace, dass jedes Ereignis durch etwas auf der CPU ausgelöst wird .

Da systrace auf ftrace basiert und ftrace auf der CPU ausgeführt wird, muss etwas auf der CPU den ftrace-Puffer schreiben, der Hardwareänderungen protokolliert. Dies bedeutet, dass Sie, wenn Sie neugierig sind, warum ein Anzeigezaun den Status geändert hat, genau zum Zeitpunkt des Übergangs sehen können, was auf der CPU ausgeführt wurde (etwas, das auf der CPU ausgeführt wird, hat diese Änderung im Protokoll ausgelöst). Dieses Konzept ist die Grundlage für die Analyse der Leistung mithilfe von Systrace.

Beispiel: Arbeitsrahmen

Dieses Beispiel beschreibt einen Systrace für eine normale UI-Pipeline. Um dem Beispiel zu folgen, laden Sie die Zip-Datei mit den Traces herunter (die auch andere in diesem Abschnitt genannte Traces enthält), entpacken Sie die Datei und öffnen Sie die Datei systrace_tutorial.html in Ihrem Browser. Seien Sie gewarnt, dass diese Systrace eine große Datei ist. Wenn Sie Systrace nicht in Ihrer täglichen Arbeit verwenden, ist dies wahrscheinlich eine viel größere Spur mit viel mehr Informationen als jemals zuvor in einer einzelnen Spur.

Für eine konsistente, regelmäßige Arbeitslast wie TouchLatency enthält die UI-Pipeline Folgendes:

  1. EventThread in SurfaceFlinger weckt den App-UI-Thread und signalisiert, dass es Zeit ist, einen neuen Frame zu rendern.
  2. Die App rendert einen Frame in UI-Thread, RenderThread und hwuiTasks unter Verwendung von CPU- und GPU-Ressourcen. Dies ist der Großteil der für die Benutzeroberfläche aufgewendeten Kapazität.
  3. Die App sendet den gerenderten Frame mithilfe eines Ordners an SurfaceFlinger. Anschließend geht SurfaceFlinger in den Ruhezustand.
  4. Ein zweiter EventThread in SurfaceFlinger aktiviert SurfaceFlinger, um die Komposition auszulösen und die Ausgabe anzuzeigen. Wenn SurfaceFlinger feststellt, dass keine Arbeit zu erledigen ist, wird es wieder eingeschlafen.
  5. SurfaceFlinger übernimmt die Komposition mit Hardware Composer (HWC) / Hardware Composer 2 (HWC2) oder GL. Die HWC / HWC2-Zusammensetzung ist schneller und hat eine geringere Leistung, weist jedoch je nach System auf einem Chip (SoC) Einschränkungen auf. Dies dauert normalerweise ~ 4-6 ms, kann sich jedoch mit Schritt 2 überschneiden, da Android-Apps immer dreifach gepuffert sind. (Während Apps immer dreifach gepuffert sind, wartet in SurfaceFlinger möglicherweise nur ein ausstehender Frame, sodass er mit doppelter Pufferung identisch erscheint.)
  6. SurfaceFlinger sendet die endgültige Ausgabe zur Anzeige an einen Anbietertreiber und geht wieder in den Ruhezustand, um auf das Aufwecken von EventThread zu warten.

Gehen wir ab 15409 ms durch den Frame:

Normale UI-Pipeline mit laufendem EventThread
Abbildung 1. Normale UI-Pipeline, EventThread wird ausgeführt

Abbildung 1 ist ein normaler Frame, der von normalen Frames umgeben ist. Dies ist ein guter Ausgangspunkt, um die Funktionsweise der UI-Pipeline zu verstehen. Die UI-Thread-Zeile für TouchLatency enthält unterschiedliche Farben zu unterschiedlichen Zeiten. Balken kennzeichnen verschiedene Zustände für den Thread:

  • Grau . Schlafen.
  • Blau. Runnable (es könnte ausgeführt werden, aber der Scheduler hat es noch nicht zum Ausführen ausgewählt).
  • Grün. Wird aktiv ausgeführt (der Scheduler glaubt, dass er ausgeführt wird).
  • Rot. Ununterbrochener Schlaf (normalerweise auf einem Schloss im Kernel). Kann auf eine E / A-Last hinweisen. Sehr nützlich zum Debuggen von Leistungsproblemen.
  • Orange. Unterbrechungsfreier Schlaf aufgrund von E / A-Belastung.

Wählen Sie die rote unterbrechungsfreie Schlafscheibe aus, um den Grund für den unterbrechungsfreien Schlaf sched_blocked_reason (verfügbar über den sched_blocked_reason sched_blocked_reason).

Während EventThread ausgeführt wird, kann der UI-Thread für TouchLatency ausgeführt werden. Klicken Sie auf den blauen Bereich, um zu sehen, was ihn geweckt hat.

UI-Thread für TouchLatency
Abbildung 2. UI-Thread für TouchLatency

Abbildung 2 zeigt, dass der TouchLatency-UI-Thread von tid 6843 geweckt wurde, was EventThread entspricht. Der UI-Thread wird aktiviert, rendert einen Frame und stellt ihn in die Warteschlange, damit SurfaceFlinger ihn verwenden kann.

Der UI-Thread wird aktiviert, rendert einen Frame und aktiviert ihn, damit SurfaceFlinger ihn verwenden kann
Abbildung 3. UI-Thread wird aktiviert, rendert einen Frame und stellt ihn in die Warteschlange, damit SurfaceFlinger ihn verwenden kann

Wenn das Tag binder_driver in einem Trace binder_driver ist, können Sie eine Binder-Transaktion auswählen, um Informationen zu allen an dieser Transaktion beteiligten Prozessen anzuzeigen.

Abbildung 4. Binder-Transaktion

Abbildung 4 zeigt, dass Binder: 6832_1 in SurfaceFlinger bei 15.423,65 ms aufgrund von tid 9579, dem RenderThread von TouchLatency, ausgeführt werden kann. Sie können queueBuffer auch auf beiden Seiten der Binder-Transaktion sehen.

Während des Warteschlangenpuffers auf der SurfaceFlinger-Seite steigt die Anzahl der ausstehenden Frames von TouchLatency von 1 auf 2.

Ausstehende Frames gehen von 1 bis 2
Abbildung 5. Ausstehende Frames gehen von 1 bis 2

Abbildung 5 zeigt die dreifache Pufferung, bei der zwei fertige Frames vorhanden sind und die App gerade mit dem Rendern eines dritten beginnt. Dies liegt daran, dass wir bereits einige Frames gelöscht haben. Daher behält die App zwei ausstehende Frames anstelle von einem bei, um zu vermeiden, dass weitere Frames gelöscht werden.

Kurz darauf wird der Hauptthread von SurfaceFlinger von einem zweiten EventThread geweckt, damit der ältere ausstehende Frame auf dem Display ausgegeben werden kann:

Der Hauptthread von SurfaceFlinger wird von einem zweiten EventThread geweckt
Abbildung 6. Der Hauptthread von SurfaceFlinger wird von einem zweiten EventThread geweckt

SurfaceFlinger speichert zuerst den älteren ausstehenden Puffer, wodurch die Anzahl der ausstehenden Puffer von 2 auf 1 verringert wird.

SurfaceFlinger rastet zuerst in den älteren ausstehenden Puffer ein
Abbildung 7. SurfaceFlinger rastet zuerst in den älteren ausstehenden Puffer ein

Nach dem Zwischenspeichern des Puffers richtet SurfaceFlinger die Komposition ein und sendet das endgültige Bild an die Anzeige. (Einige dieser Abschnitte sind als Teil des mdss aktiviert, sodass sie möglicherweise nicht in Ihrem SoC enthalten sind.)

SurfaceFlinger richtet die Komposition ein und sendet den endgültigen Frame
Abbildung 8. SurfaceFlinger richtet die Komposition ein und sendet den endgültigen Frame

Als nächstes wird mdss_fb0 auf CPU 0 mdss_fb0 . mdss_fb0 ist der Kernel-Thread der Anzeigepipeline zum Ausgeben eines gerenderten Frames an die Anzeige. Wir können mdss_fb0 als eigene Zeile in der Ablaufverfolgung sehen (zur Ansicht nach unten scrollen).

mdss_fb0 wird auf CPU 0 aktiviert
Abbildung 9. mdss_fb0 wird auf CPU 0 aktiviert

mdss_fb0 wacht auf, läuft kurz, geht in den unterbrechungsfreien Schlaf und wacht dann wieder auf.

Beispiel: Nicht funktionierender Rahmen

Dieses Beispiel beschreibt eine Systrace, die zum Debuggen von Pixel / Pixel XL-Jitter verwendet wird. Um dem Beispiel zu folgen, laden Sie die Zip-Datei mit den Traces herunter (einschließlich anderer Traces, auf die in diesem Abschnitt verwiesen wird), entpacken Sie die Datei und öffnen Sie die Datei systrace_tutorial.html in Ihrem Browser.

Wenn Sie die Systrace öffnen, sehen Sie ungefähr Folgendes:

TouchLatency läuft auf Pixel XL mit den meisten aktivierten Optionen
Abbildung 10. Auf Pixel XL ausgeführte TouchLatency (die meisten Optionen sind aktiviert, einschließlich mdss- und kgsl-Tracepoints)

Wenn Sie nach Ruck suchen, überprüfen Sie die Zeile FrameMissed unter SurfaceFlinger. FrameMissed ist eine Verbesserung der Lebensqualität von HWC2. Wenn Sie systrace für andere Geräte anzeigen, ist die FrameMissed-Zeile möglicherweise nicht vorhanden, wenn das Gerät HWC2 nicht verwendet. In beiden Fällen korreliert FrameMissed damit, dass SurfaceFlinger eine seiner extrem regelmäßigen Laufzeiten und eine unveränderte com.prefabulated.touchlatency an ausstehenden com.prefabulated.touchlatency für die App ( com.prefabulated.touchlatency ) bei einem vsync fehlt.

FrameMissed-Korrelation mit SurfaceFlinger
Abbildung 11. FrameMissed-Korrelation mit SurfaceFlinger

Fig. 11 zeigt einen fehlenden Rahmen bei 15598,29 ms. SurfaceFlinger wachte im vsync-Intervall kurz auf und schlief ohne Arbeit wieder ein, was bedeutet, dass SurfaceFlinger feststellte, dass es sich nicht lohnte, erneut einen Frame an das Display zu senden. Warum?

Um zu verstehen, wie die Pipeline für diesen Frame ausgefallen ist, überprüfen Sie zunächst das obige Arbeitsrahmenbeispiel, um festzustellen, wie eine normale UI-Pipeline in systrace angezeigt wird. Wenn Sie fertig sind, kehren Sie zum fehlenden Frame zurück und arbeiten Sie rückwärts. Beachten Sie, dass SurfaceFlinger aufwacht und sofort schlafen geht. Wenn Sie die Anzahl der ausstehenden Frames in TouchLatency anzeigen, gibt es zwei Frames (ein guter Hinweis, um herauszufinden, was los ist).

SurfaceFlinger wacht auf und geht sofort schlafen
Abbildung 12. SurfaceFlinger wacht auf und geht sofort schlafen

Da wir in SurfaceFlinger Frames haben, ist dies kein App-Problem. Außerdem wacht SurfaceFlinger zum richtigen Zeitpunkt auf, sodass es sich nicht um ein SurfaceFlinger-Problem handelt. Wenn sowohl SurfaceFlinger als auch die App normal aussehen, liegt wahrscheinlich ein Treiberproblem vor.

Da die mdss und sync aktiviert sind, können wir Informationen zu den Zäunen abrufen (die vom Anzeigetreiber und SurfaceFlinger gemeinsam genutzt werden), die steuern, wann Frames an die Anzeige gesendet werden. Diese Zäune sind unter mdss_fb0_retire , was mdss_fb0_retire , wann ein Rahmen auf dem Display angezeigt wird. Diese Zäune werden als Teil der sync Trace-Kategorie bereitgestellt. Welche Zäune bestimmten Ereignissen in SurfaceFlinger entsprechen, hängt von Ihrem SOC und Treiberstapel ab. Arbeiten Sie daher mit Ihrem SOC-Anbieter zusammen, um die Bedeutung der Zaunkategorien in Ihren Spuren zu verstehen.

mdss_fb0_retire Zäune
Abbildung 13. mdss_fb0_retire-Zäune

Abbildung 13 zeigt einen Frame, der 33 ms und nicht wie erwartet 16,7 ms lang angezeigt wurde. In der Mitte dieses Slice hätte dieser Rahmen durch einen neuen ersetzt werden sollen, war es aber nicht. Sehen Sie sich den vorherigen Frame an und suchen Sie nach etwas.

Rahmen vor kaputtem Rahmen
Abbildung 14. Rahmen vor dem kaputten Rahmen

Abbildung 14 zeigt 14.482 ms pro Frame. Das gebrochene Zwei-Frame-Segment betrug 33,6 ms, was ungefähr dem entspricht, was wir für zwei Frames erwarten würden (wir rendern mit 60 Hz, 16,7 ms pro Frame, was nahe liegt). Aber 14.482 ms sind überhaupt nicht in der Nähe von 16.7 ms, was darauf hindeutet, dass etwas mit der Display-Pipe sehr falsch ist.

Untersuchen Sie genau, wo dieser Zaun endet, um festzustellen, was ihn kontrolliert.

Untersuchen Sie das Zaunende
Abbildung 15. Untersuchen Sie das Zaunende

Eine Workqueue enthält __vsync_retire_work_handler , der ausgeführt wird, wenn sich der Zaun ändert. Wenn Sie sich die Kernelquelle ansehen, sehen Sie, dass sie Teil des Anzeigetreibers ist. Es scheint sich auf dem kritischen Pfad für die Anzeige-Pipeline zu befinden, daher muss es so schnell wie möglich ausgeführt werden. Es kann für ungefähr 70 US-Dollar ausgeführt werden (keine lange Planungsverzögerung), aber es ist eine Warteschlange und wird möglicherweise nicht genau geplant.

Überprüfen Sie den vorherigen Frame, um festzustellen, ob dies dazu beigetragen hat. Manchmal kann sich Jitter im Laufe der Zeit summieren und schließlich zu einer versäumten Frist führen.

Vorheriger Frame
Abbildung 16. Vorheriger Frame

Die ausführbare Zeile auf dem kworker ist nicht sichtbar, da der Viewer sie bei Auswahl weiß färbt, aber die Statistiken erzählen die Geschichte: 2,3 ms Scheduler-Verzögerung für einen Teil des kritischen Pfads der Anzeigepipeline sind schlecht . Bevor Sie fortfahren, beheben Sie die Verzögerung, die durch Verschieben dieses Teils des kritischen Pfads der Anzeigepipeline von einer Workqueue (die als SCHED_OTHER CFS-Thread ausgeführt wird) zu einem dedizierten SCHED_FIFO Kthread behoben wird. Diese Funktion benötigt Timing-Garantien, die Workqueues nicht bereitstellen können (und sollen).

Ist das der Grund für den Ruck? Es ist schwer abschließend zu sagen. Abgesehen von leicht zu diagnostizierenden Fällen wie Kernel-Lock-Konflikten, die dazu führen, dass displaykritische Threads in den Ruhezustand versetzt werden, geben Traces das Problem normalerweise nicht an. Könnte dieser Jitter die Ursache für den heruntergefallenen Frame gewesen sein? Absolut. Die Zaunzeiten sollten 16,7 ms betragen, aber sie liegen in den Frames, die zum abgelegten Frame führen, überhaupt nicht in der Nähe davon. In Anbetracht der engen Kopplung der Anzeige-Pipeline ist es möglich, dass der Jitter um die Zaun-Timings zu einem heruntergefallenen Frame führte.

In diesem Beispiel bestand die Lösung darin, __vsync_retire_work_handler von einer Workqueue in einen dedizierten kthread zu konvertieren. Dies führte zu spürbaren Jitterverbesserungen und einem verringerten Ruck im Bouncing-Ball-Test. Nachfolgende Spuren zeigen Zaunzeiten, die sehr nahe bei 16,7 ms liegen.