Na czym polega systrace

systrace to główne narzędzie do analizy wydajności urządzeń z Androidem. W rzeczywistości całkowicie opracowujemy też inne narzędzia. To kod po stronie hosta wokół słowa atrace – plik wykonywalny po stronie urządzenia, który kontroluje przestrzeń użytkownika śledzenia i konfiguruje ftrace oraz główny mechanizm śledzenia w systemie Linux jądro. systrace używa atrace, aby umożliwić śledzenie, a następnie odczytuje bufor ftrace i a wszystko to w niezależnej przeglądarce HTML. Choć nowsze jądra obsługują dla systemu Linux Enhanced Berkeley PacketFilter (eBPF), zapoznaj się z tą dokumentacją dotyczy jądra systemu 3.18 (nie eFPF), ponieważ XL).

System systrace należy do zespołów Google Android i Google Chrome. open source Projekt Catapult. W oprócz systrace, Catapult zawiera też inne przydatne narzędzia. Przykład: ftrace ma więcej funkcji niż można bezpośrednio włączyć przez systrace lub atrace i zawiera zaawansowane funkcje, które mają kluczowe znaczenie dla wydajności debugowania . Te funkcje wymagają dostępu do roota i często wymagają nowego jądra.

Uruchom systrace

Podczas debugowania zakłóceń na Pixelu/Pixelu XL zacznij od tego polecenie:

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

W połączeniu z dodatkowymi punktami śledzenia wymaganymi przez GPU i wyświetlanie działania potoku, umożliwia to śledzenie od danych wejściowych użytkownika do ramki wyświetlane na ekranie. Ustaw rozmiar bufora na duży, by uniknąć utraty zdarzeń (ponieważ bez dużego bufora niektóre procesory nie zawierają żadnych zdarzeń po w jakimś punkcie logu czasu).

Korzystając z systrace, pamiętaj, że każde zdarzenie jest uruchamianych przez jakiś element procesora.

Ponieważ systrace jest zbudowany na procesorach ftrace i ftrace, coś na procesorze musi zapisać bufor ftrace, który rejestruje zmiany sprzętowe. Oznacza to, że jeśli zastanawiasz się, dlaczego ogrodzenie wyświetlacza uległo zmianie, można sprawdzić, co było uruchomione na procesorze w momencie przejścia (działanie uruchomione przez procesor wywołało tę zmianę w dzienniku). Ten koncepcja to podstawa analizy wydajności za pomocą systrace.

Przykład: ramka robocza

W tym przykładzie opisano systrace dla normalnego potoku interfejsu użytkownika. Do przeczytania zgodnie z przykładem: pobierz plik zip ze śledzeniem śledzenia (która zawiera też inne logi czasu, o których wspominamy w tej sekcji), rozpakuj plik, i otwórz plik systrace_tutorial.html w przeglądarce. Ostrzeżenie że ta systrace jest dużym plikiem; chyba że na co dzień używasz systrace pracy, ten ślad jest prawdopodobnie znacznie bardziej obszerny i zawiera więcej informacji jak dotąd na jednym śladzie.

Aby zapewnić spójne, okresowe zadania, takie jak TouchLatency, potok UI zawiera następujące elementy:

1. EventThread w SurfaceFlinger wybudza wątek UI aplikacji, sygnalizując, że czas już na nią. do renderowania nowej klatki.
2. Aplikacja renderuje ramkę w wątku UI, RenderThread i hwuiTasks, używając procesora i Zasoby GPU. To większość pojemności wykorzystanej w interfejsie użytkownika.
3. Aplikacja wysyła wyrenderowaną ramkę do SurfaceFlinger za pomocą separatora, a potem SurfaceFlinger zasypia.
4. Drugie zdarzenie EventThread w usłudze SurfaceFlinger wybudza SurfaceFlinger, aby aktywować aktywator. i wyświetlanie danych wyjściowych. Jeśli SurfaceFlinger stwierdzi, że nie ma pracy, gdy nie uda się go wykonać, wraca do snu.
5. SurfaceFlinger obsługuje kompozycję za pomocą narzędzia Hardware Composer (HWC) lub sprzętu Composer 2 (HWC2) lub GL. skład HWC/HWC2, jest szybszy i mniejszy, ale ma ograniczenia w zależności od układu układu Układ SOC. Zwykle zajmuje to ok. 4–6 ms, ale może się pokrywać z krokiem 2, ponieważ Android aplikacje są zawsze trzykrotnie buforowane. (Aplikacje są zawsze potrójnie buforowane, może być tylko jedna oczekująca klatka oczekująca w SurfaceFlinger, co powoduje pojawienie się i taki sam jak podwójne buforowanie).
6. SurfaceFlinger wysyła ostateczne dane wyjściowe do wyświetlenia ze sterownikiem dostawcy i przechodzi powrót do trybu uśpienia, oczekiwanie na wybudzenie EventThread.

Przyjrzyjmy się klatce rozpoczynającej się od 15 409 ms:

.

Rysunek 1 przedstawia normalną klatkę otoczoną normalnymi klatkami, więc za punkt wyjścia do zrozumienia, jak działa potok UI. Wiersz wątku UI w przypadku TouchLatency uwzględnia różne kolory w różnym czasie. Słupki oznaczają różne stany wątku:

• Szary Spanie.
• Niebieski. Gotowe do działania (mogło zostać uruchomione, ale algorytm szeregowania nie został uruchomiony zaznaczył je do uruchomienia).
• Zielony. Aktywna (harmonogram algorytm uważa, że ).
• Czerwony Sen niezakłócony (zwykle śpi z zamkiem) w jądrze). Może wskazywać obciążenie wejścia-wyjścia. Zdecydowanie przydatne przy debugowaniu problemy z wydajnością.
• Pomarańczowy. Nieprzerwany sen z powodu obciążenia wejścia-wyjścia.

Aby wyświetlić przyczynę nieprzerwanego snu (dostępnego sched_blocked_reason), wybierz czerwony punkt śledzenia niemożliwego do przerwania segment snu.

Gdy usługa EventThread jest uruchomiona, wątek interfejsu TouchLatency zmienia się w . Aby sprawdzić, co obudziło, kliknij niebieską sekcję.

.

Na ilustracji 2 widać, że wątek interfejsu TouchLatency został wywołany przez kod tid 6843, który odpowiada EventThread. Wątek UI wybudza, renderuje ramkę i dodaje ją do kolejki. do wykorzystania przez SurfaceFlinger.

.

Jeśli tag binder_driver jest włączony w śledzeniu, możesz wybrać transakcji powiązanych, aby mieć wgląd w informacje o wszystkich procesach związanych z transakcji.

.

Rysunek 4 pokazuje, że przy 15 423,65 ms Binder:6832_1 w SurfaceFlinger pojawia się wykonalna ze względu na identyfikator 9579, który jest elementem RenderThread interfejsu TouchLatency. Możesz też zobaczyć kolejki buforowe po obu stronach transakcji segregatora.

W oknie kolejki kolejki po stronie SurfaceFlinger liczba oczekujących liczba klatek w czasie TouchLatency zmienia się z 1 na 2.

.

Rysunek 5 przedstawia potrójne buforowanie, w którym występują dwie ukończone klatki, właśnie zacznie renderować trzecią. To dlatego, że już wcześniej obniżyliśmy więc aplikacja zachowa 2 oczekujące klatki, a nie jedną. kolejne klatki pominięte.

Wkrótce potem główny wątek SurfaceFlinger jest wybudzony przez drugi wątek EventThread, może wyświetlić na ekranie starszą oczekującą ramkę:

.

SurfaceFlinger najpierw wczytuje starszy bufor oczekujący, co powoduje, że oczekiwanie na zmniejszenie liczby buforów z 2 do 1.

.

Po zablokowaniu bufora SurfaceFlinger konfiguruje kompozycję i przesyła plik ostatnią klatkę na ekranie. (Niektóre z tych sekcji są włączone w ramach mdss, więc mogą nie być uwzględnione w układzie SOC).

.

Następnie mdss_fb0 aktywuje się przy CPU 0. mdss_fb0 to wyświetlania wątku jądra potoku w celu wygenerowania renderowanej ramki na wyświetlaczu. Widzimy pole mdss_fb0 jako własny wiersz w śledzeniu (przewiń w dół, widok danych).

mdss_fb0 się obudzi, biega na chwilę, przechodzi w tryb niezakłócony, i ponownie się wybudza.

Przykład: niedziałająca ramka

W tym przykładzie opisano systrace używaną do debugowania zakłóceń w działaniu Pixela lub Pixela XL. Do zgodnie z przykładem: pobierz plik zip ze śladami (który zawiera inne ślady wymienione w tej sekcji ), rozpakuj plik i otwórz plik systrace_tutorial.html w przeglądarki.

Po otwarciu systrace zobaczysz coś takiego:

.

W przypadku wykrycia zacinania zwróć uwagę na wiersz Frame Notice (Brak ramki) w obszarze SurfaceFlinger. Frame Missing to poprawa jakości życia oferowana przez HWC2. Podczas wyświetlania systrace w przypadku innych urządzeń, wiersz Brak klatki nie może być widoczny, jeśli urządzenie nie używa HWC2. W: w przypadku braku klatka kluczowa jest skorelowana z brakiem jednego ze swoich elementów w usłudze SurfaceFlinger wyjątkowo regularne środowiska wykonawcze i niezmieniona liczba oczekujących buforów w przypadku aplikacji. (com.prefabulated.touchlatency) podczas synchronizacji vsync.

.

Rysunek 11 pokazuje brakującą klatkę o czasie 15 598,29&nb/ms. Platforma SurfaceFlinger na chwilę się obudziła o po interwale vsync i powrót do trybu uśpienia bez wykonywania pracy, co oznacza Usługa SurfaceFlinger stwierdziła, że nie warto wysyłać ramki na wyświetlacz ponownie. Dlaczego?

Aby zrozumieć, jak doszło do uszkodzenia potoku w tej ramce, najpierw przejrzyj przykładowej ramki roboczej powyżej, aby zobaczyć, jak normalny potok UI wygląda w systrace. Gdy wszystko będzie gotowe, wróć do brakującej klatki i przechodź do tyłu. Zwróć uwagę, że SurfaceFlinger wybudza się i natychmiast zasypia. Podczas wyświetlania liczby oczekujące klatki z TouchLatency, są dwie klatki (dobra wskazówka, co się dzieje).

.

Ponieważ w SurfaceFlinger mamy ramki, nie jest to problem z aplikacją. Ponadto SurfaceFlinger budzi się o odpowiedniej godzinie, więc to nie jest SurfaceFlinger Google Cloud. Jeśli SurfaceFlinger i aplikacja wyglądają normalnie, problem ze sterownikiem.

Punkty śledzenia mdss i sync są włączone, możemy uzyskać informacje o ogrodzeniach (udostępniane między sterownikiem wyświetlacza SurfaceFlinger), które określają, kiedy klatki są przesyłane na wyświetlacz. Te ogrodzenia są wymienione w wierszu mdss_fb0_retire, który wskazuje, kiedy na wyświetlaczu pojawia się klatka. Te ogrodzenia są potraktowane jako w kategorii logów czasu sync. Które ogrodzenia odpowiadają konkretne zdarzenia w SurfaceFlinger zależą od SOC i stosunku sterowników, więc podjąć współpracę z dostawcą SOC, aby zrozumieć znaczenie kategorii płotów w Twojej ślady czasu.

Ilustracja 13 pokazuje klatkę, która była wyświetlana przez 33 ms, a nie 16,7 ms, zgodnie z oczekiwaniami. W połowie tego wycinka ta klatka powinna zostać zastąpiona nową ale tak nie było. Wyświetl poprzednią klatkę i poszukaj innych elementów.

.

Ilustracja 14 przedstawia 14,482 ms klatki. Przerwany segment z 2 klatkami miał długość 33,6 ms. czyli mniej więcej w przypadku 2 klatek (renderujemy je z częstotliwością 60 Hz i 16, 7 ms). na klatkę, czyli podobną). 14,482 ms nie jest jednak bliskie 16,7 ms, sugerują, że coś jest bardzo nie tak z kreską na wyświetlaczu.

Sprawdź dokładnie, w którym miejscu kończy się płot, aby ustalić, co je kontroluje.

.

Kolejka zawiera __vsync_retire_work_handler, czyli i biegną, gdy ogrodzenie się zmienia. W źródle jądra widać, To część sterownika ekranu. Wydaje się, że kluczowe znaczenie dla potoku wyświetlania, więc musi on być jak najkrótszy. Jest może działać przez około 70 us (nie jest to długie opóźnienie w harmonogramie), ale jest to kolejka robocza, mogą nie być dokładnie określone.

Przyjrzyj się poprzedniej ramce, aby ustalić, czy ma to związek z problemem. czasami zakłócenia mogą się sumować z czasem i w efekcie doprowadzić do przekroczenia terminu.

.

wykorzystywana linia w elemencie kworker jest niewidoczna, ponieważ użytkownik ją zmienia biały po wybraniu, ale statystyki pokazują historię: 2,3 ms algorytmu szeregowania opóźnienie na części ścieżki krytycznej potoku do wyświetlania jest złe. Zanim przejdziesz dalej, usuń opóźnienie, które polega na przeniesieniu tej części wyświetl ścieżkę krytyczną potoku z kolejki roboczej (która działa jako SCHED_OTHER wątku CFS) do dedykowanego wątku SCHED_FIFO kthread. Ta funkcja wymaga gwarancji czasowych, których kolejki robocze nie mogą (i nie są) które oferuję.

Czy to jest przyczyną tych zacięć? Trudno powiedzieć jednoznacznie. Spoza domeny łatwych do diagnozowania przypadków, np. rywalizacja o blokowanie jądra systemu, która powoduje krytyczne wątki snu, ślady zwykle nie określają problemu. Czy te zakłócenia mogą być przyczyną utraty ramki? Oczywiście. czas ogrodzenia powinien wynosić 16,7 ms, ale nie jest on wcale zbliżony do tego w klatkach do upuszczonej klatki. Biorąc pod uwagę to, jak ściśle sprzężone są potoki reklam displayowych jest możliwe, że zakłócenia w okolicy płotu spowodowały spadek ramki.

W tym przykładzie rozwiązanie polegało na konwersji __vsync_retire_work_handler z kolejki roboczej do dedykowanego zespołu kthread. Dzięki temu można było zauważyć zauważalną poprawę jakości dźwięku i zmniejszyć liczbę zagniecenia test z odbijającą się piłką. Kolejne ślady pokazują czasy ogrodzenia, które unoszą się bardzo blisko do 16,7 ms.