Sprawdź logi czasu

Widok logów czasu w programie profilującym CPU zapewnia kilka sposobów wyświetlania informacji z zarejestrowanych logów czasu.

Ślady metod i logów czasu funkcji możesz wyświetlić bezpośrednio na osi czasu Threads oraz karty Wykres flame, Od góry, Od dołu do góry i Zdarzenia w panelu Analiza. W przypadku ramek stosu wywołań możesz wyświetlić część kodu, która została wykonana, i powód wywołania. W przypadku logów czasu Zdarzenia śledzenia możesz wyświetlać bezpośrednio na osi czasu Wątki, a karty Wykres flame, Od góry, Od dołu i Zdarzenia w panelu Analiza.

Aby ułatwić sobie poruszanie się po wykresach wywołań i zdarzeniach śledzenia, dostępne są skróty klawiszowe.

Sprawdzanie śladów za pomocą wykresu wywołań

Wykres wywołań przedstawia w sposób graficzny ślad metody lub ślad funkcji, gdzie okres i czas wywołania jest przedstawione na osi poziomej, a jego wywołania – wzdłuż osi pionowej. Wywołania systemowych interfejsów API są wyświetlane na pomarańczowo, wywołania metod Twojej aplikacji – na zielono, a wywołania innych interfejsów API (w tym interfejsów API w języku Java) – na niebiesko. Rysunek 4 przedstawia przykładowy wykres wywołań i ilustruje koncepcje czasu własnego, czasu dzieci i całkowitego czasu w przypadku danej metody lub funkcji. Więcej informacji o tych zagadnieniach znajdziesz w sekcji poświęconej sprawdzaniu logów czasu za pomocą operacji od góry do dołu i od dołu do góry.

Rysunek 1. Przykładowy wykres wywołań, który przedstawia siebie, dzieci i całkowity czas w przypadku metody D.

Wskazówka: aby przejść do kodu źródłowego metody lub funkcji, kliknij ją prawym przyciskiem myszy i wybierz Przejdź do źródła. Działa to na wszystkich kartach panelu Analiza.

Sprawdzanie śladów za pomocą karty Wykres płomieniowy

Karta Wykres płomieniowy zawiera odwrócony wykres wywołań, który agreguje identyczne stosy wywołań. Oznacza to, że zbierane są identyczne metody lub funkcje z tą samą sekwencją wywołań i przedstawione na wykresie płomieniowym jako jeden dłuższy słupek (zamiast jako kilka krótszych słupków, jak widać na wykresie wywołań). Dzięki temu łatwiej sprawdzisz, które metody lub funkcje wykorzystują najwięcej czasu. Oznacza to jednak, że oś pozioma nie przedstawia osi czasu, a zamiast tego pokazuje względny czas potrzebny na wykonanie poszczególnych metod lub funkcji.

Aby lepiej zrozumieć tę koncepcję, spójrzmy na wykres wywołań na Rysunku 2. Zauważ, że metoda D wielokrotnie wywołuje metodę B (B1, B2 i B3), a niektóre z tych wywołań typu B wykonują wiele wywołań C (C1 i C3).

Rysunek 2. Wykres wywołań z wieloma wywołaniami metod o tej samej sekwencji wywołań.

Ponieważ komórki B1, B2 i B3 mają tę samą sekwencję wywołań (A → D → B), są one łączone, jak widać na Rysunku 3. Podobnie dane z klas C1 i C3 są zagregowane, ponieważ mają tę samą sekwencję wywołań (A → D → B → C). Należy pamiętać, że grupa C2 nie została uwzględniona, ponieważ ma inną sekwencję wywołań (A → D → C).

Rysunek 3. Agregowanie identycznych metod, które korzystają z tego samego stosu wywołań.

Zagregowane wywołania posłużą do utworzenia wykresu płomieniowego, jak pokazano na Rysunku 4. Pamiętaj, że w przypadku każdego wywołania na wykresie płomieniowym jako pierwsze pojawiają się wywołania, które wykorzystują najwięcej czasu pracy procesora.

Rysunek 4. Wykres płomieniowy przedstawiony na grafice 5.

Sprawdź logi czasu za pomocą metod od góry do dołu i od dołu

Karta Od góry zawiera listę wywołań, w których rozwinięcie węzła metody lub funkcji wyświetla jego wywołania. Rysunek 5 przedstawia wykres wywołań od góry do dołu z Rys. 1. Każda strzałka na wykresie wskazuje osobę wywołującą.

Jak widać na Rysunku 5, rozwinięcie węzła metody A na karcie Od góry powoduje wyświetlenie jej wywołań, metod B i D. Następnie rozwinięcie węzła dla metody D powoduje ujawnienie jego wywołań, metod B, C itd. Podobnie jak w przypadku karty Wykres flama, drzewo od góry zbiera informacje z logu czasu dla identycznych metod, które mają ten sam stos wywołań. Oznacza to, że karta Wykres flamyczny przedstawia kartę Od góry w sposób graficzny.

Karta Od góry zawiera te informacje, które pomagają opisać czas pracy procesora poświęcony na każde wywołanie (czasy są również wyrażone jako procent łącznego czasu wątku w wybranym zakresie):

  • Sam: czas, przez jaki wywołanie metody lub funkcji spędziło na wykonaniu własnego kodu, a nie przez wywołania tej metody, jak to widać na Rysunku 1 dla metody D.
  • Elementy podrzędne: czas wykonania wywołań metody lub funkcji, a nie własnego kodu, jak widać na Rysunku 1 dla metody D.
  • Łącznie: suma czasu ego i dzieci danej metody. Jest to łączny czas wykonywania wywołania przez aplikację, tak jak to widać na Rysunku 1 dla metody D.

Rysunek 5. Drzewo z góry

Rysunek 6. Drzewo od dołu do góry dla metody C z Rysunku 5.

Karta Od dołu do góry zawiera listę wywołań, w których rozwinięcie funkcji lub węzła metody zawiera elementy wywołujące. Korzystając z przykładowego logu czasu pokazanego na Rysunku 5, na rys. 6 przedstawiamy drzewo od dołu do użycia w metodzie C. Otwarcie węzła dla metody C w drzewie od dołu do góry spowoduje wyświetlenie wszystkich unikalnych elementów wywołujących, metod B i D. Zwróć uwagę, że chociaż wersja B wywołuje kod C dwukrotnie, pojawia się tylko raz podczas rozwijania węzła dla metody C w drzewie od dołu do góry. Następnie rozwinięcie węzła B wyświetli jego element wywołujący, metody A i D.

Karta Od dołu do góry przydaje się do sortowania metod lub funkcji według tych, które wykorzystują najwięcej (lub najmniej) czasu procesora. Możesz zbadać każdy węzeł, aby sprawdzić, które elementy wywołujące spędzają najwięcej czasu procesora na wywoływaniu tych metod lub funkcji. W porównaniu z drzewem od góry do dołu informacje o czasie poszczególnych metod lub funkcji w drzewie u dołu odnoszą się do metody znajdującej się na górze każdego drzewa (górny węzeł). Czas pracy procesora jest również wyrażony jako procent łącznego czasu trwania wątku podczas nagrywania. W tabeli poniżej objaśniamy sposób interpretowania informacji o czasie w przypadku górnego węzła i jego elementów wywołujących (węzłów podrzędnych).

Własnym Dzieci Razem
Metoda lub funkcja na górze drzewa od dołu (górny węzeł) Reprezentuje łączny czas wykonywania kodu przez metodę lub funkcję, a nie przez jej wywołania. W porównaniu z najwyższym drzewem te informacje o czasie stanowią sumę wszystkich wywołań tej metody lub funkcji w trakcie nagrywania. Reprezentuje łączny czas wykonywania wywołań metody lub funkcji przez metodę lub funkcję, a nie własny kod. W porównaniu z najwyższym drzewem te informacje o czasie stanowią sumę wszystkich wywołań tej metody lub funkcji w czasie trwania nagrania. Suma czasu spędzonego na własnym koncie i czasu dzieci.
Wywołujący (węzły podrzędne) Reprezentuje łączny czas użytkownika wywoływanego przez obiekt wywołujący. Jeśli na przykład skorzystamy z drzewa oddolnego na Rysunku 6, czas własny dla metody B będzie równy sumie czasu własnego wykonania dla każdego wykonania metody C przy wywołaniu metody B. Reprezentuje łączny czas elementów podrzędnych wywołania podczas wywoływania przez element wywołujący. Jeśli na przykład użyjemy drzewa oddolnego na Rysunku 6, czas podrzędny dla metody B byłby równy sumie czasów podrzędnych dla każdego wykonania metody C, jeśli zostanie wywołana przez B. Suma czasu spędzonego na własnym koncie i czasu dzieci.

Uwaga: w przypadku danego nagrania Android Studio przestaje zbierać nowe dane, gdy program profilujący osiągnie limit rozmiaru pliku (nie zatrzymuje to jednak nagrywania). Zwykle dzieje się to znacznie szybciej podczas wykonywania instruktażowych logów czasu, ponieważ ten typ śledzenia zbiera więcej danych w krótszym czasie niż w przypadku próbkowanych logów czasu. Jeśli wydłużysz czas inspekcji do okresu rejestracji, który wystąpił po osiągnięciu limitu, dane o czasie w panelu śledzenia nie ulegną zmianie (ponieważ nie będą dostępne żadne nowe dane). Dodatkowo w panelu śledzenia wyświetla się wartość NaN, gdy wybierzesz tylko tę część nagrania, która nie ma dostępnych danych.

Sprawdzanie logów czasu za pomocą tabeli Zdarzenia

Tabela zdarzeń zawiera listę wszystkich wywołań w aktualnie wybranym wątku. Można je sortować, klikając nagłówki kolumn. Wybierając wiersz w tabeli, możesz przejść na osi czasu do czasu rozpoczęcia i zakończenia wybranej rozmowy. Dzięki temu możesz dokładnie zlokalizować zdarzenia na osi czasu.

Rysunek 7. Wyświetlanie karty Zdarzenia w panelu Analiza.

Sprawdzanie ramek stosu wywołań

Stosy wywołań ułatwiają sprawdzanie, która część kodu została wykonana i dlaczego. Jeśli na potrzeby programu Java/Kotlin zbierane jest przykładowe nagranie stosu wywołań, stos wywołań zwykle zawiera nie tylko kod Java/Kotlin, ale także ramki z natywnego kodu JNI, wirtualnej maszyny Java (np. android::AndroidRuntime::start) i jądro systemu ([kernel.kallsyms]+offset). Dzieje się tak, ponieważ programy Java/Kotlin są zwykle wykonywane na wirtualnej maszynie Java. Kod natywny jest wymagany do uruchomienia programu oraz do komunikacji przez program z systemem i sprzętem. Program do profilowania prezentuje te ramki pod kątem dokładności, jednak w zależności od badania mogą być one przydatne lub nieprzydatne. Program profilujący umożliwia zwijanie ramek, które Cię nie interesują, w celu ukrycia informacji nieistotnych podczas badania.

W poniższym przykładzie ten log czasu zawiera wiele ramek z etykietą [kernel.kallsyms]+offset, które obecnie nie są przydatne podczas programowania.

Przykładowy ślad połączenia

Aby zwinąć ramki w jedną, kliknij przycisk Zwiń ramki na pasku narzędzi, wybierz ścieżki, które chcesz zwinąć, i kliknij przycisk Zastosuj, aby zastosować zmiany. W tym przykładzie ścieżka to [kernel.kallsyms].

Przykład menu Simpleperf

Spowoduje to zwinięcie ramek odpowiadających wybranej ścieżce zarówno w panelu po lewej, jak i w prawym panelu, jak pokazano poniżej.

Przykłady zwiniętych ramek Simpleperf

Sprawdź logi czasu systemu

Podczas sprawdzania logu czasu systemowego możesz przejrzeć zdarzenia śledzenia na osi czasu Threads, aby zobaczyć szczegóły zdarzeń występujących w każdym wątku. Najedź kursorem myszy na zdarzenie, aby zobaczyć jego nazwę i czas w poszczególnych stanach. Kliknij zdarzenie, aby wyświetlić więcej informacji w panelu Analiza.

Sprawdzanie logów czasu systemu: rdzenie procesora

Oprócz danych dotyczących harmonogramu procesora ślady systemu obejmują też częstotliwość procesora według rdzeni. Pokazuje on ilość aktywności na poszczególnych rdzeniach i pokazuje, które z nich są „dużymi” czy „małymi” rdzeniami we współczesnych procesorach mobilnych.

Rysunek 8. Wyświetlam aktywność procesora i zdarzenia śledzenia w wątku renderowania.

Okienko Rdzenie procesora (jak pokazano na Rysunku 8) zawiera zaplanowaną aktywność wątku dla każdego rdzenia. Najedź kursorem na aktywność wątku, aby zobaczyć, w którym wątku jest uruchomiony ten rdzeń w danym momencie.

Więcej informacji o badaniu informacji z logów czasu systemu znajdziesz w sekcji Badanie problemów z wydajnością interfejsu użytkownika w dokumentacji systrace.

Sprawdzanie logów czasu systemu: oś czasu renderowania ramki

Możesz sprawdzić, ile czasu zajmuje aplikacji wyrenderowanie każdej klatki w wątku głównym, oraz RenderThread, aby zbadać wąskie gardła, które powodują zacinanie się interfejsu i małą liczbę klatek. Aby dowiedzieć się, jak używać logów czasu systemu do badania i zmniejszania zacięć się interfejsu, przeczytaj artykuł o wykrywaniu zacinania się interfejsu.

Sprawdzanie logów czasu systemu: pamięć procesów (RSS)

W przypadku aplikacji wdrożonych na urządzeniach z Androidem 9 lub nowszym sekcja Pamięć procesu (RSS) pokazuje ilość pamięci fizycznej używanej obecnie przez aplikację.

Rysunek 9. Wyświetlanie pamięci fizycznej w narzędziu do profilowania.

Łącznie

Jest to łączna ilość pamięci fizycznej używanej obecnie przez Twój proces. W systemach typu Unix wartość ta jest nazywana „rozmiarem zestawu rezydentnego”. Jest to połączenie całej pamięci używanej przez przydziały anonimowe, mapowania plików i przydziały pamięci współdzielonej.

W przypadku programistów Windows rozmiar zestawu rezydentnego jest odpowiednikiem rozmiaru zestawu roboczego.

Przydzielone

Ten licznik śledzi, ile pamięci fizycznej jest obecnie wykorzystywane przez normalne przydziały pamięci procesu. Są to przydziały anonimowe (nieobsługiwane przez konkretny plik) i prywatne (nieudostępniane). W większości aplikacji składają się one z alokacji sterty (z malloc lub new) oraz pamięci stosu. W przypadku zastąpienia z pamięci fizycznej przydziały te są zapisywane w pliku wymiany systemu.

Mapowania plików

Ten licznik śledzi ilość pamięci fizycznej używanej przez proces do mapowań plików, czyli pamięć zmapowaną z plików na region pamięci przez menedżera pamięci.

Udostępnione

Ten licznik śledzi ilość pamięci fizycznej wykorzystywaną do współużytkowania pamięci między tym procesem a innymi procesami w systemie.