Czytanie raportów o błędach

Błędy występują w ramach każdego typu rozwoju, a zgłoszenia błędów są kluczowe do ich identyfikowania i rozwiązywania. Wszystkie wersje Androida obsługują przechwytywanie raportów o błędach za pomocą narzędzia Android Debug Bridge (adb). Wersje Androida 4.2 i nowsze obsługują opcję dla deweloperów umożliwiającą przechwytywanie raportów o błędach i udostępnianie ich e-mailem, na Dysku itp.

Raporty o błędach Androida zawierają dane w formacie tekstowym (.txt) w formatach dumpsys, dumpstatelogcat, co umożliwia łatwe wyszukiwanie określonych treści. W następnych sekcjach znajdziesz szczegółowe informacje o składnikach raportu o błędach, opisy typowych problemów oraz przydatne wskazówki i polecenia grep, które pomogą Ci znaleźć dzienniki związane z tymi błędami. Większość sekcji zawiera też przykłady polecenia grep i wyjścia lub wyjścia dumpsys.

Logcat

Plik dziennika logcat to ciąg znaków zawierający wszystkie informacje logcat. Część system jest zarezerwowana dla frameworka i ma dłuższą historię niż część główna, która zawiera wszystko inne. Każdy wiersz zwykle zaczyna się od timestamp UID PID TID log-level, ale w starszych wersjach Androida UID może nie być wymieniony.

Wyświetlanie dziennika zdarzeń

Ten plik dziennika zawiera ciągi znaków odpowiadające binarnym komunikatom dziennika. Jest on mniej chaotyczny niż dziennik logcat, ale też nieco trudniejszy do odczytania. Podczas wyświetlania dzienników zdarzeń możesz w tej sekcji wyszukać określony identyfikator procesu (PID), aby sprawdzić, co robił ten proces. Podstawowy format to: timestamp PID TID log-level log-tag tag-values.

Poziomy logowania:

  • V: szczegółowy
  • D: debug
  • I: informacje
  • W: ostrzeżenie
  • E: błąd

 

Inne przydatne tagi dziennika zdarzeń znajdziesz w katalogu /services/core/java/com/android/server/EventLogTags.logtags.

Błędy ANR i blokady

Raporty o błędach mogą pomóc w określeniu przyczyny błędów Aplikacja nie odpowiada (ANR) i zdarzeń blokady.

Identyfikowanie aplikacji, które nie odpowiadają

Jeśli aplikacja nie reaguje w określonym czasie (zwykle z powodu zablokowanego lub zajętego głównego wątku), system zabija proces i zbiera stos do /data/anr. Aby dowiedzieć się, co spowodowało błąd ANR, w dzienniku zdarzeń binarnych wykonaj grep na am_anr.

Możesz też użyć polecenia grep, aby wyszukać ANR in w logu logcat. Zawiera on więcej informacji o tym, co w momencie wystąpienia ANR korzystało z procesora.

Znajdowanie zrzutów stosu

Często można znaleźć zrzuty stosu odpowiadające błędom ANR. Upewnij się, że sygnatura czasowa i PID w śladach maszyny wirtualnej są zgodne z badanym ANR, a następnie sprawdź główny wątek procesu. Pamiętaj:

  • Wątek główny podaje tylko, co robił w momencie wystąpienia błędu ANR. Nie musi to być prawdziwa przyczyna błędu. (zbiór danych w raporcie o błędzie może być niewinny; coś innego może być zablokowane przez długi czas, ale nie na tyle długo, aby użyć funkcji ANR).
  • Może istnieć więcej niż 1 zestaw dzienników wywołań (VM TRACES JUST NOWVM TRACES AT LAST ANR). Upewnij się, że wyświetlasz właściwą sekcję.

Znajdowanie blokad

Blokady często pojawiają się jako ANR, ponieważ wątki utknęły. Jeśli impas dotknie serwera systemowego, program nadzorczy ostatecznie go zatrzyma, co spowoduje pojawienie się w dzienniku wpisu podobnego do tego: WATCHDOG KILLING SYSTEM PROCESS. Z perspektywy użytkownika urządzenie się ponownie uruchamia, choć technicznie jest to restart w czasie działania, a nie prawdziwe ponowne uruchomienie.

  • Podczas restartu w czasie działania serwer systemu przestaje działać i zostaje ponownie uruchomiony. Użytkownik widzi, że urządzenie wraca do animacji uruchamiania.
  • W przypadku ponownego uruchamiania kernel uległ awarii, a użytkownik widzi, że urządzenie wraca do logo rozruchu Google.

Aby znaleźć blokady, sprawdź sekcje z wykresami VM pod kątem wzoru, w którym wątek A oczekuje na coś, co jest przetrzymywane przez wątek B, który z kolei oczekuje na coś, co jest przetrzymywane przez wątek A.

Działania

Aktywność to element aplikacji, który zapewnia użytkownikom ekran do interakcji, np. do wybierania numeru, robienia zdjęć czy wysyłania e-maili. Z perspektywy raportu o błędach aktywność to pojedyncza czynność, którą może wykonać użytkownik, dlatego bardzo ważne jest zlokalizowanie aktywności, która była w centrum uwagi podczas awarii. Aktywności (za pomocą ActivityManager) uruchamiają procesy, więc zlokalizowanie wszystkich miejsc, w których procesy danej aktywności się uruchamiają i zawieszają, może też pomóc w rozwiązywaniu problemów.

Wyświetlanie ukierunkowanych aktywności

Aby wyświetlić historię działań skupionych, wyszukaj am_focused_activity.

Rozpoczyna się proces wyświetlania

Aby wyświetlić historię uruchamiania procesów, wyszukaj Start proc.

Sprawdzanie, czy urządzenie jest przeciążone

Aby ustalić, czy urządzenie zawiesza się, sprawdź, czy w krótkim czasie nie nastąpiło nietypowe zwiększenie aktywności w okolicach am_proc_died i am_proc_start.

Pamięć

Urządzenia z Androidem często mają ograniczoną pamięć fizyczną, dlatego zarządzanie pamięcią RAM jest bardzo ważne. Raporty o błędach zawierają kilka wskaźników niskiego poziomu pamięci oraz stan dump, który zawiera migawkę pamięci.

Identyfikowanie niskiego poziomu pamięci

Niewystarczająca ilość pamięci może spowodować, że system będzie się trawić, ponieważ zabija niektóre procesy, aby zwolnić pamięć, ale nadal uruchamia inne procesy. Aby wyświetlić dowody potwierdzające niski poziom pamięci, sprawdź, czy w dzienniku zdarzeń binarnych występują liczne wpisy am_proc_died i am_proc_start.

Niewystarczająca ilość pamięci może też spowolnić przełączanie zadań i uniemożliwić próby powrotu (ponieważ zadanie, do którego użytkownik próbuje wrócić, zostało zakończone). Jeśli uruchomiliśmy go ponownie, ponownie uruchomi się, gdy użytkownik dotknie przycisku strony głównej. Logi pokazują, że uruchomił się ponownie.

Wyświetlanie wskaźników historycznych

Wpis am_low_memory w dzienniku zdarzeń binarnych wskazuje, że ostatni proces z pamięci podręcznej przestał działać. Następnie system zaczyna zabijać usługi.

Wyświetlanie wskaźników przeciążenia

Inne wskaźniki przeciążenia systemu (przekierowywanie, bezpośrednie odzyskiwanie itp.) to kswapd, kworker i mmcqd. (Pamiętaj, że zbierany raport o błędach może wpływać na wskaźniki thrashingu).

Dzienniki ANR mogą zawierać podobny migawek pamięci.

Pobieranie zrzutu pamięci

Zrzut pamięci to stan pamięci, który zawiera listę procesów Java i natywnych (więcej informacji znajdziesz w sekcji Wyświetlanie ogólnych alokacji pamięci). Pamiętaj, że snapshot pokazuje tylko stan systemu w określonym momencie. Przed zrobieniem snapshotu system mógł być w lepszym (lub gorszym) stanie.

Nadawanie

Aplikacje generują transmisje, aby wysyłać zdarzenia w ramach bieżącej aplikacji lub do innej aplikacji. Odbiornicy transmisji subskrybują określone wiadomości (za pomocą filtrów), co umożliwia im słuchanie i odpowiadanie na transmisję. Raporty o błędach zawierają informacje o wysłanych i niewysłanych transmisjach, a także dane dumpsys wszystkich odbiorników słuchających daną transmisję.

Wyświetlanie transmisji historycznych

Transmisje historyczne to te, które zostały już wysłane i wyświetlane w odwrotnej kolejności chronologicznej.

Sekcja Podsumowanie zawiera przegląd ostatnich 300 transmisji na pierwszym planie i ostatnich 300 transmisji w tle.

Sekcja szczegóły zawiera pełne informacje o ostatnich 50 transmisjach na pierwszym planie i ostatnich 50 transmisjach w tle, a także listę odbiorców każdej transmisji. Odbiorcy, którzy mają:

  • Wpis BroadcastFilter jest rejestrowany w czasie wykonywania i wysyłany tylko do już uruchomionych procesów.
  • Wpis ResolveInfo jest rejestrowany za pomocą wpisów w pliku manifestu. Menedżer aktywności uruchamia proces dla każdego ResolveInfo, jeśli nie jest już uruchomiony.

Wyświetlanie aktywnych transmisji

Aktywnymi transmisjami są te, które nie zostały jeszcze wysłane. Duża liczba wiadomości w kolejce oznacza, że system nie może wysyłać transmisji z odpowiednią szybkością.

Wyświetlanie odbiorców transmisji

Aby wyświetlić listę odbiorników odbierających transmisję, sprawdź tabelę Resolver Table w sekcji dumpsys activity broadcasts. Poniższy przykład wyświetla wszystkich odbiorników słuchających USER_PRESENT.

Monitorowanie rywalizacji

Rejestrowanie rywalizacji o monitor może czasami wskazywać rzeczywistą rywalizację o monitor, ale najczęściej wskazuje na to, że system jest tak obciążony, że wszystko zwalnia. W dzienniku systemowym lub dzienniku zdarzeń możesz zobaczyć długie zdarzenia monitorowania zarejestrowane przez ART.

W dzienniku systemowym:

10-01 18:12:44.343 29761 29914 W art     : Long monitor contention event with owner method=void android.database.sqlite.SQLiteClosable.acquireReference() from SQLiteClosable.java:52 waiters=0 for 3.914s

W dzienniku zdarzeń:

10-01 18:12:44.364 29761 29914 I dvm_lock_sample: [com.google.android.youtube,0,pool-3-thread-9,3914,ScheduledTaskMaster.java,138,SQLiteClosable.java,52,100]

Kompilacja w tle

Kompilacja może być kosztowna i obciążać urządzenie.

Kompilacja może odbywać się w tle podczas pobierania aktualizacji Sklepu Google Play. W takim przypadku wiadomości z aplikacji Sklep Google Play (finsky) i installd pojawiają się przed wiadomościami dex2oat.

Kompilacja może też odbywać się w tle, gdy aplikacja wczytuje plik dex, który nie został jeszcze skompilowany. W takim przypadku nie zobaczysz rejestrowania zdarzeń finsky ani installd.

Narracja

Określenie przebiegu problemu (jak się zaczął, co się działo, jak zareagował system) wymaga dokładnego zestawienia zdarzeń. Za pomocą informacji w raporcie o błędach możesz zsynchronizować osi czasu w różnych logach i określić dokładną sygnaturę czasową raportu o błędach.

Synchronizacja harmonogramów

Raport o błędzie odzwierciedla wiele równoległych przedziałów czasowych: dziennika systemu, dziennika zdarzeń, dziennika jądra oraz wielu specjalistycznych przedziałów czasowych dotyczących transmisji, statystyk baterii itp. Niestety przedziały czasowe są często raportowane z różnymi podstawami czasowymi.

Sygnatury czasowe systemu i dziennika zdarzeń są podawane w tej samej strefie czasowej co użytkownik (podobnie jak większość innych sygnatur czasowych). Gdy użytkownik kliknie przycisk strony głównej, dziennik systemowy zgłosi:

10-03 17:19:52.939  1963  2071 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 on display 0

W przypadku tego samego działania dziennik zdarzeń zgłasza:

10-03 17:19:54.279  1963  2071 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL]

Logi jądra (dmesg) używają innej podstawy czasowej, oznaczając elementy logów sekundami od momentu zakończenia działania bootloadera. Aby zarejestrować ten interwał czasowy w innych interwałach czasowych, wyszukaj komunikaty zawieszenie wyjścia i zawieszenie wejścia:

<6>[201640.779997] PM: suspend exit 2015-10-03 19:11:06.646094058 UTC
…
<6>[201644.854315] PM: suspend entry 2015-10-03 19:11:10.720416452 UTC

Ponieważ dzienniki jądra mogą nie zawierać czasu zawieszenia, należy zarejestrować dziennik etapami między komunikatami o wejściu i wyjściu z zawieszenia. Dodatkowo dzienniki jądra używają strefy czasowej UTC i muszą być dostosowywane do strefy czasowej użytkownika.

Określanie czasu raportu o błędach

Aby określić, kiedy został utworzony raport o błędzie, najpierw sprawdź dziennik systemowy (Logcat) na urządzeniu dumpstate: begin:

10-03 17:19:54.322 19398 19398 I dumpstate: begin

Następnie sprawdź sygnatury czasowe w dzienniku jądra (dmesg) dla wiadomości Starting service 'bugreport':

<5>[207064.285315] init: Starting service 'bugreport'...

Aby powiązać 2 zdarzenia, postępuj od końca do początku, pamiętając o ograniczeniach podanych w artykule Synchronizowanie harmonogramów. Po rozpoczęciu tworzenia raportu o błędzie dzieje się wiele, ale większość działań nie jest zbyt przydatna, ponieważ samo tworzenie raportu o błędzie znacznie obciąża system.

Moc

Dziennik zdarzeń zawiera stan zasilania ekranu: 0 to ekran wyłączony, 1 to ekran włączony, a 2 to blokada klawiatury.

Raporty o błędach zawierają też statystyki dotyczące blokad aktywacji – mechanizmu używanego przez deweloperów aplikacji do wskazywania, że ich aplikacja wymaga włączenia urządzenia. (Więcej informacji o blokadach uśpienia znajdziesz w funkcjach PowerManager.WakeLockKeep the CPU on).

Aggregowane statystyki dotyczące czasu trwania blokady uśpienia śledzą tylko czas, w którym blokada uśpienia była faktycznie odpowiedzialna za utrzymywanie urządzenia w stanie uśpienia, i nie uwzględniają czasu z włączonym ekranem. Jeśli dodatkowo jednocześnie występuje kilka blokad uśpienia ekranu, czas trwania blokady jest rozłożony na te blokady.

Aby uzyskać więcej informacji o stanach zasilania, użyj Battery Historian, czyli narzędzia open source od Google do analizowania elementów zużywających baterię za pomocą plików raportów o błędach Androida.

Pakiety

Sekcja DUMP OF SERVICE package zawiera wersje aplikacji (oraz inne przydatne informacje).

Procesy

Raporty o błędach zawierają ogromną ilość danych o procesach, w tym czas rozpoczęcia i zakończenia, czas działania, powiązane usługi, wynik oom_adj itp. Więcej informacji o tym, jak Android zarządza procesami, znajdziesz w artykule Procesy i wątki.

Określanie czasu wykonywania procesu

Sekcja procstats zawiera pełne statystyki dotyczące czasu działania procesów i powiązanych usług. Aby wyświetlić szybkie podsumowanie w formie zrozumiałej dla człowieka tabeli, wyszukaj AGGREGATED OVER, aby wyświetlić dane z ostatnich 3 lub 24 godzin, a następnie wyszukaj Summary:, aby wyświetlić listę procesów, czas ich działania z różnymi priorytetami oraz zużycie pamięci RAM w formacie min-średnia-maks. PSS/min-średnia-maks. USS.

Przyczyny, dla których proces jest uruchomiony

W sekcji dumpsys activity processes znajdują się wszystkie aktualnie działające procesy uporządkowane według wartości oom_adj (Android wskazuje znaczenie procesu, przypisując mu wartość oom_adj, która może być dynamicznie aktualizowana przez ActivityManager). Dane wyjściowe są podobne do danych migawki pamięci, ale zawierają dodatkowe informacje o tym, co powoduje uruchomienie procesu. W przykładzie poniżej pogrubione wpisy wskazują, że proces gms.persistent jest wykonywany z priorytetem vis (widocznym), ponieważ proces systemowy jest powiązany z usługą NetworkLocationService.

Skanowania

Aby zidentyfikować aplikacje wykonujące nadmierne skanowania Bluetooth Low Energy (BLE):

  • Znajdowanie wiadomości z dziennika dotyczących BluetoothLeScanner:
    $ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
    07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
    
  • Znajdź identyfikator PID w wiadomościach z dziennika. W tym przykładzie „24840” i „24851” to PID (identyfikator procesu) i TID (identyfikator wątku).
  • Znajdź aplikację powiązaną z identyfikatorem PID:
    PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}
    

    W tym przykładzie nazwa pakietu to com.badapp.

  • Aby znaleźć aplikację, która jest odpowiedzialna za problem, wyszukaj nazwę pakietu w Google Play: https://play.google.com/store/apps/details?id=com.badapp.

Uwaga: w przypadku urządzeń z Androidem 7.0 system zbiera dane dotyczące skanowania BLE i kojarzy te działania z aplikacją inicjującą. Więcej informacji znajdziesz w artykule Skanowanie w trybie niskiego zużycia energii (LE) i Bluetooth.