Czytanie raportów o błędach

Błędy występują w ramach każdego typu rozwoju, a zgłoszenia błędów są kluczowe dla ich identyfikowania i rozwiązywania. Wszystkie wersje Androida obsługują przechwytywanie raportów o błędach za pomocą Android Debug Bridge (adb). Android w wersji 4.2 i nowszej obsługuje 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) dumpsys, dumpstatelogcat, dzięki czemu można łatwo wyszukiwać konkretne 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 zaczyna się zwykle 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 szumny 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 zawieszanie się aplikacji

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 odpowiada w określonym czasie (zwykle z powodu zablokowanego lub zajętego głównego wątku), system zabija proces i zrzuca stos do /data/anr. Aby dowiedzieć się, co spowodowało błąd ANR, użyj polecenia grep w pliku dziennika zdarzeń binarnych, aby wyszukać ciąg znaków am_anr.

Możesz też użyć polecenia grep, aby wyszukać ANR in w logu logcat, który zawiera 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 ANR, który badasz, a następnie sprawdź główny wątek procesu. Pamiętaj:

  • Wątek główny podaje tylko, co robił wątek w momencie wystąpienia błędu ANR. Nie musi to być rzeczywistą przyczyną tego błędu. (zbiór danych w raporcie o błędzie może być niewinny; coś innego może być zablokowane od dłuższego czasu, 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, zostanie on ostatecznie zamknięty przez watchdoga, 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 maszyny wirtualnej pod kątem wzoru, w którym wątek A czeka na coś, co jest blokowane przez wątek B, który z kolei czeka na coś, co jest blokowane przez wątek A.

Działania

Aktywność to komponent aplikacji, który zapewnia użytkownikom ekran do interakcji, aby wykonać takie czynności jak wybieranie numeru, robienie zdjęć czy wysyłanie 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ę skupionych działań, 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 występuje nietypowy wzrost 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 uruchomiony był program uruchamiający, to gdy użytkownik dotknie przycisku strony głównej, zostanie on ponownie uruchomiony, a z logów będzie wynikać, że ponownie wczytuje swoje treści.

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 zatrzymywać 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 natyw (więcej informacji znajdziesz w sekcji Wyświetlanie alokacji pamięci ogólnej). 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. Odbiorniki 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 odbiorców każdej transmisji. Odbiorcy, którzy mają:

  • Wpis BroadcastFilter jest rejestrowany w czasie wykonywania i wysyłany tylko do procesów, które są już uruchomione.
  • 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 pokazuje 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, ż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 rzetelnego 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.

Harmonogramy synchronizacji

Raport o błędzie odzwierciedla wiele równoległych linii czasowych: dziennika systemu, dziennika zdarzeń, dziennika jądra oraz wielu specjalistycznych linii czasowych dotyczących transmisji, statystyk baterii itp. Niestety linie czasowe są często raportowane przy użyciu różnych baz czasowych.

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 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ść aktywności 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, czyli mechanizmu używanego przez deweloperów aplikacji do wskazywania, że aplikacja musi pozostać włączona. (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 rzeczywiście 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 listy, wyszukaj AGGREGATED OVER, aby wyświetlić dane z ostatnich 3 lub 24 godzin, a potem 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 uruchomiony 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ź 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 Low Energy (LE) i Bluetooth.