Systrace verstehen

„systrace“ ist das wichtigste Tool zur Analyse der Leistung von Android-Geräten. Es ist jedoch ein Wrapper um andere Tools. Es ist der hostseitige Wrapper. Um atrace, die geräteseitige ausführbare Datei, die den Nutzerbereich steuert Tracing und richtet ftrace sowie den primären Tracing-Mechanismus unter Linux ein. Kernel. "systrace" verwendet "atrace", um das Tracing zu aktivieren, und liest dann den ftrace-Zwischenspeicher. in einem eigenständigen HTML-Viewer. Neuere Kernel unterstützen für Linux Enhanced Berkeley Packet Filter (eBPF) finden Sie in der folgenden Dokumentation bezieht sich auf den Kernel 3.18 (kein eFPF), da dieser beim Pixel/Pixel verwendet wurde. XL).

systrace gehört zu den Google Android- und Google Chrome-Teams und ist als Teil des Katapultprojekt: In Neben Systrace enthält Catapult weitere nützliche Dienstprogramme. Beispiel: ftrace hat mehr Funktionen, die direkt von systrace oder atrace aktiviert werden können, enthält einige erweiterte Funktionen, die für das Debugging der Leistung wichtig sind Probleme. (Diese Funktionen erfordern Root-Zugriff und oft einen neuen Kernel.)

Systrace ausführen

Beginnen Sie bei der Behebung des Jitters auf Pixel/Pixel XL mit Folgendem: Befehl:

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

In Kombination mit den zusätzlichen Tracepoints, die für GPU und Anzeige erforderlich sind Pipeline-Aktivität haben, können Sie von der Nutzereingabe bis zum Frame zurückverfolgen. die auf dem Bildschirm angezeigt werden. Legen Sie die Puffergröße auf einen großen Wert fest, um zu vermeiden, -Ereignisse (da einige CPUs ohne einen großen Zwischenspeicher keine Ereignisse nach an einem beliebigen Punkt im Trace).

Denken Sie bei der Ausführung von Systrace daran, dass jedes Ereignis durch etwas in der CPU ausgelöst.

Da systrace auf ftrace aufbaut und ftrace auf der CPU ausgeführt wird, muss in der CPU der ftrace-Zwischenspeicher geschrieben werden, der Hardwareänderungen protokolliert. Wenn Sie also wissen möchten, warum sich der Status eines Displayzauns geändert hat, Sie können sehen, was genau zum Zeitpunkt des Übergangs auf der CPU ausgeführt wurde. (etwas, das auf der CPU ausgeführt wird, hat diese Änderung im Log ausgelöst). Dieses Leistungsanalyse mit "systrace".

Beispiel: Arbeits-Frame

In diesem Beispiel wird ein Systrace für eine normale UI-Pipeline beschrieben. So kannst du mitmachen: mit dem Beispiel: ZIP-Datei mit Traces herunterladen (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. Warnung dass dieses Systrace eine große Datei ist, es sei denn, Sie verwenden Systrace ist dies wahrscheinlich ein viel größerer Trace mit viel mehr Informationen, in einem einzelnen Trace gesehen.

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

  1. EventThread in SurfaceFlinger weckt den UI-Thread der App und signalisiert, dass es Zeit ist um einen neuen Frame zu rendern.
  2. Die App rendert einen Frame im UI-Thread, RenderThread und hwuiTasks unter Verwendung von CPU und GPU-Ressourcen Dies macht den Großteil der für die Benutzeroberfläche aufgewendeten Kapazität aus.
  3. Die App sendet den gerenderten Frame mithilfe eines Binders an SurfaceFlinger und SurfaceFlinger wechselt in den Ruhemodus.
  4. Ein zweiter EventThread in SurfaceFlinger weckt SurfaceFlinger zum Auslösen und Anzeigeausgabe. Wenn SurfaceFlinger feststellt, dass es keine Arbeit zum wechselt er wieder in den Ruhemodus.
  5. SurfaceFlinger übernimmt die Zusammensetzung mithilfe von Hardware Composer (HWC)/Hardware. Composer 2 (HWC2) oder GL. HWC/HWC2-Zusammensetzung ist schneller und hat weniger Energie, aber je nach System auf einem Chip (SoC) Dies dauert normalerweise etwa 4–6 ms, kann sich aber mit Schritt 2 überschneiden, da Android Apps werden immer dreifach zwischengespeichert. Apps werden zwar immer dreifach gepuffert, ist möglicherweise nur ein ausstehender Frame in SurfaceFlinger vorhanden, sodass er identisch mit doppelter Zwischenspeicherung.)
  6. SurfaceFlinger sendet die endgültige Ausgabe zur Anzeige mit einem Anbietertreiber und sendet wieder in den Ruhemodus, ich warte auf EventThread-Aufwachen.

Gehen wir den Frame ab 15.409 ms durch:

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Normale UI-Pipeline mit ausgeführtem EventThread <ph type="x-smartling-placeholder">
</ph> Abbildung 1: Normale UI-Pipeline, EventThread wird ausgeführt

Abbildung 1 zeigt einen normalen Frame, der von normalen Frames umgeben ist. zu verstehen, wie die UI-Pipeline funktioniert. Zeile des UI-Threads für TouchLatenzzeit verwenden verschiedene Farben zu unterschiedlichen Zeiten. Balken stehen für verschiedene Status für den Thread:

  • Grau: Schlafen.
  • Blau. Ausführbar (er könnte ausgeführt werden, aber der Planer hat dies nicht getan). ausgeführt werden soll).
  • Grün: Aktiv (der Planer glaubt, dass es ausgeführt werden.
  • Rot: Unterbrechungsfreier Schlaf (normalerweise auf einem Schloss-Display aktiv) im Kernel). Dies kann ein Hinweis auf die E/A-Last sein. Äußerst nützlich für die Fehlerbehebung Probleme mit der Leistung.
  • Orange. Unterbrechungsfreier Ruhemodus aufgrund der E/A-Last.

Um den Grund für den unterbrechungsfreien Schlaf anzuzeigen (verfügbar unter sched_blocked_reason, wählen Sie das rote unterbrechungsfreie Schlafscheibe.

Während EventThread ausgeführt wird, wird der UI-Thread für TouchLatenz zu ausführbar sind. Wenn du sehen möchtest, was ihn geweckt hat, klicke auf den blauen Bereich.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> UI-Thread für TouchLatenz <ph type="x-smartling-placeholder">
</ph> Abbildung 2: UI-Thread für TouchLatenz

Abbildung 2 zeigt, wie der TouchLatenz-UI-Thread von tid 6843 geweckt wurde, was entspricht EventThread. Der UI-Thread wird aktiviert, rendert einen Frame und wird in die Warteschlange gestellt. für SurfaceFlinger.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Der UI-Thread löst den Ruhemodus aus, rendert einen Frame und fügt ihn in die Warteschlange ein, damit SurfaceFlinger ihn verarbeiten kann. <ph type="x-smartling-placeholder">
</ph> Abbildung 3: Der UI-Thread wird aktiviert, rendert einen Frame und stellt ihn in die Warteschlange ein für SurfaceFlinger

Wenn das Tag binder_driver in einem Trace aktiviert ist, können Sie ein binder-Transaktion aufrufen, um Informationen zu allen Transaktion.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> <ph type="x-smartling-placeholder">
</ph> Abbildung 4: Binder-Transaktion

In Abbildung 4 sehen Sie, dass in SurfaceFlinger bei 15.423,65 ms Binder:6832_1 zu ausführbar, weil tid 9579, der RenderThread von TouchLatenz ist. Sie können auch Siehe „queueBuffer“ auf beiden Seiten der Binder-Transaktion.

Während des QueueBuffer auf der SurfaceFlinger-Seite ist die Anzahl der ausstehenden Frames aus TouchLatenz geht von 1 auf 2.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Ausstehende Frames werden von 1 auf 2 gesetzt <ph type="x-smartling-placeholder">
</ph> Abbildung 5: Ausstehende Frames werden von 1 auf 2 gesetzt

Abbildung 5 zeigt die dreifache Zwischenspeicherung, bei der zwei abgeschlossene Frames vorhanden sind. ein drittes zu rendern. Das liegt daran, dass wir sodass die App zwei ausstehende Frames beibehält weitere verworfene Frames hinzu.

Kurz darauf wird der Hauptthread von SurfaceFlinger durch einen zweiten EventThread geweckt, sodass kann der ältere Pending-Frame an den Bildschirm ausgegeben werden:

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Der Hauptthread von SurfaceFlinger wird von einem zweiten EventThread geweckt <ph type="x-smartling-placeholder">
</ph> Abbildung 6. Der Hauptthread von SurfaceFlinger wird um eine Sekunde geweckt Ereignisthread

SurfaceFlinger speichert zuerst den älteren ausstehenden Zwischenspeicher, wodurch die Die ausstehende Anzahl der Puffer wurde von 2 auf 1 gesenkt.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> SurfaceFlinger verbindet sich zuerst mit dem älteren ausstehenden Zwischenspeicher. <ph type="x-smartling-placeholder">
</ph> Abbildung 7: SurfaceFlinger verbindet sich zuerst mit der älteren, Zwischenspeicher

Nach dem Speichern des Zwischenspeichers richtet SurfaceFlinger die Komposition ein und sendet die zum Display übertragen werden. Einige dieser Bereiche werden im Rahmen des mdss-Tracepoint, sodass sie möglicherweise nicht in deinem SoC enthalten sind.)

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> SurfaceFlinger richtet die Komposition ein und sendet den letzten Frame. <ph type="x-smartling-placeholder">
</ph> Abbildung 8: SurfaceFlinger richtet die Komposition ein und sendet die letzter Frame

Als Nächstes wird mdss_fb0 bei CPU 0 beendet. mdss_fb0 ist der/die/das Kernel-Thread der Pipeline anzeigen, um einen gerenderten Frame an die Anzeige auszugeben. Wir können mdss_fb0 als eigene Zeile im Trace sehen (scrollen Sie nach unten Ansicht).

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> mdss_fb0 wacht bei CPU 0 auf <ph type="x-smartling-placeholder">
</ph> Abbildung 9. mdss_fb0-Aktivierung bei CPU 0

mdss_fb0 wacht auf, rennt kurz, wechselt in den unterbrechungsfreien Schlaf und wacht wieder auf.

Beispiel: Nicht funktionstüchtiger Frame

In diesem Beispiel wird ein Systrace zum Debuggen des Pixel-/Pixel XL-Jitters beschrieben. Bis folgen Sie dem Beispiel: ZIP-Datei herunterladen Datei mit Traces, die auch andere Traces enthält, auf die in diesem ), entpacken Sie die Datei und öffnen Sie sie in Ihremsystrace_tutorial.html Browser.

Wenn Sie Systrace öffnen, sehen Sie in etwa Folgendes:

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> TouchLatenz auf Pixel XL mit aktivierten meisten Optionen <ph type="x-smartling-placeholder">
</ph> Abbildung 10. Auf Pixel XL ausgeführte TouchLatenzzeit (die meisten Optionen) aktiviert, einschließlich mdss- und kgsl-Tracepoints)

Wenn Sie nach einer Verzögerung suchen, überprüfen Sie die Zeile „FrameMissed“ unter „SurfaceFlinger“. FrameMissed ist eine durch HWC2 ermöglichte Verbesserung der Lebensqualität. Beim Ansehen Systrace für andere Geräte vornehmen, wird die Zeile "FrameMissed" möglicherweise nicht angezeigt, wenn das Gerät verwendet HWC2 nicht. In beiden FrameMissed korreliert mit SurfaceFlinger, bei dem eine seiner extrem regelmäßige Laufzeiten und eine unveränderte Anzahl ausstehender Puffer für die Anwendung (com.prefabulated.touchlatency) bei vsync.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> FrameMissed-Korrelation mit SurfaceFlinger <ph type="x-smartling-placeholder">
</ph> Abbildung 11. FrameMissed-Korrelation mit SurfaceFlinger

Abbildung 11 zeigt einen verpassten Frame bei 15.598,29 ms. SurfaceFlinger wachte kurz auf vsync-Intervall an und gingen zurück in den Ruhemodus, ohne irgendetwas zu tun. SurfaceFlinger fand heraus, dass es sich nicht lohnt, einen Frame an das Display zu senden. noch einmal. Was steckt dahinter?

Um zu verstehen, wie die Pipeline für diesen Frame aufgeschlüsselt ist, überprüfen Sie zuerst die Beispiel für einen Arbeits-Frame weiter oben, um zu sehen, wie eine normale UI-Pipeline in Systrace aussieht. Wenn Sie bereit sind, kehren Sie zum verpassten Frame zurück und arbeiten Sie rückwärts. Beachten Sie, dass SurfaceFlinger wacht auf und geht sofort ein. Bei Anzeige der Anzahl der für ausstehende Frames aus TouchLatenzzeit, gibt es zwei Frames (ein guter Hinweis zur herausfinden, wo das Problem liegt).

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> SurfaceFlinger wacht auf und geht sofort schlafen. <ph type="x-smartling-placeholder">
</ph> Abbildung 12. SurfaceFlinger wird aktiviert und Schlaf

Da wir Frames in SurfaceFlinger verwenden, handelt es sich nicht um ein App-Problem. Außerdem SurfaceFlinger wird zur richtigen Zeit aktiviert, daher ist es kein SurfaceFlinger Problem. Wenn SurfaceFlinger und die App normal aussehen, ist es wahrscheinlich Treiberproblem.

Da die Tracepoints mdss und sync aktiviert sind, können wir Informationen über die Zäune erhalten (gemeinsam zwischen dem Fahrer des Displays und SurfaceFlinger), die festlegen, wann Frames an das Display gesendet werden. Diese Zäune sind unter mdss_fb0_retire aufgeführt, zeigt an, wann sich ein Frame auf dem Display befindet. Diese Zäune werden als der Trace-Kategorie sync. Welche Zäune entsprechen Ereignisse in SurfaceFlinger sind von Ihrem Sicherheitscenter und Ihrem Treiberstack abhängig. können Sie mit Ihrem SOC-Anbieter zusammenarbeiten, Spuren.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> mdss_fb0_Zäune ausmustern <ph type="x-smartling-placeholder">
</ph> Abbildung 13. mdss_fb0_zäune ausmustern

Abbildung 13 zeigt einen Frame, der 33 ms lang angezeigt wurde und nicht wie erwartet 16,7 ms. Nach der Hälfte des Abschnitts hätte dieser Frame durch einen neuen ersetzt werden sollen. aber nicht. Sieh dir den vorherigen Frame an und suche nach etwas.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Vorheriger zum fehlerhaften Frame <ph type="x-smartling-placeholder">
</ph> Abbildung 14. Vorheriger zum fehlerhaften Frame

Abbildung 14 zeigt 14,482 ms pro Frame. Das unterbrochene Segment mit zwei Frames betrug 33,6 ms. Das entspricht in etwa den Erwartungen bei zwei Frames (bei 60 Hz, 16,7 ms). pro Frame, was nahe dran ist). Aber 14,482 ms entspricht nicht nahe 16,7 ms, was darauf hindeutet, dass etwas mit dem Anzeigerohr nicht stimmt.

Finde heraus, wo genau der Zaun endet, um herauszufinden, wo er sich kontrolliert.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Zaunende prüfen <ph type="x-smartling-placeholder">
</ph> Abbildung 15. Zaunende prüfen

Eine Arbeitswarteschlange enthält __vsync_retire_work_handler, was wenn sich der Zaun ändert. In der Kernel-Quelle sehen Sie, Es ist Teil des Displaytreibers. Es scheint sich auf die kritische für die Anzeige-Pipeline, sodass sie so schnell wie möglich ausgeführt werden muss. Es ist für etwa 70 US ausführbar (keine lange Planungsverzögerung), aber es ist eine Arbeitswarteschlange und werden möglicherweise nicht genau geplant.

Sieh im vorherigen Frame nach, ob das dazu beigetragen hat: manchmal zittert sich im Laufe der Zeit summieren und letztendlich dazu führen, dass die Frist nicht eingehalten wird.

<ph type="x-smartling-placeholder">
</ph> <ph type="x-smartling-placeholder"></ph> Vorheriger Frame <ph type="x-smartling-placeholder">
</ph> Abbildung 16. Vorheriger Frame

Die ausführbare Zeile im Kworker ist nicht sichtbar, da der Viewer sie dreht weiß, wenn es ausgewählt ist, aber die Statistiken verraten es: 2,3 ms des Planers Die Verzögerung für einen Teil des kritischen Pfads der Display-Pipeline ist schlecht. Bevor Sie fortfahren, korrigieren Sie die Verzögerung, indem Sie diesen Teil des den kritischen Pfad der Pipeline aus einer Arbeitswarteschlange anzeigen (die als SCHED_OTHER CFS-Thread) zu einem dedizierten SCHED_FIFO kthread verwenden. Diese Funktion benötigt Timing-Garantien, die Arbeitswarteschlangen bereitzustellen.

Ist das der Grund für die Verzögerung? Schwer zu sagen. Außerhalb von einfach zu diagnostizierende Fälle wie Konflikte mit Kernel-Sperrungen, die anzeigekritische Ereignisse verursachen Threads in den Ruhezustand versetzt, geben Traces normalerweise nicht das Problem an. Könnte dieser Jitter die Ursache des verworfenen Frames gewesen sein? Selbstverständlich. Die Fence-Zeiten sollten 16,7 ms betragen, aber sie liegen in den Frames überhaupt nicht nahe daran. bis zum verworfenen Frame führt. Da die Display-Pipeline eng gekoppelt ist, ist es möglich, dass der Jitter um die Zaunzeit zu einer Frame.

In diesem Beispiel war die Lösung __vsync_retire_work_handler von einer Arbeitswarteschlange in eine dedizierte Warteschlange kthread verwenden. Dies führte zu einer deutlichen Verbesserung des Jitters und reduzierten Verzögerungen im hüpfenden Balltest. Nachfolgende Traces zeigen Timings von Zaun, die sehr dicht schweben auf 16,7 ms eingestellt.