Czytanie raportów o błędach

Błędy są nieodłącznym elementem każdego procesu tworzenia oprogramowania, a zgłoszenia błędów mają kluczowe znaczenie dla identyfikowania i rozwiązywania problemów. Wszystkie wersje Androida obsługują tworzenie raportów o błędach za pomocą narzędzia Android Debug Bridge (adb). Wersje Androida 4.2 i nowsze obsługują opcję programisty, która umożliwia tworzenie raportów o błędach i udostępnianie ich e-mailem, na Dysku itp.

Raporty o błędach na Androidzie zawierają dane dumpsys, dumpstatelogcat w formacie tekstowym (.txt), co ułatwia wyszukiwanie konkretnych treści. W sekcjach poniżej znajdziesz szczegółowe informacje o elementach raportu o błędzie, opis typowych problemów oraz przydatne wskazówki i grep polecenia do wyszukiwania logów powiązanych z tymi błędami. Większość sekcji zawiera też przykłady grep poleceń i danych wyjściowych lub dumpsys danych wyjściowych.

Logcat

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

Wyświetlanie dziennika zdarzeń

Ten dziennik zawiera reprezentacje ciągów znaków wiadomości dziennika w formacie binarnym. Jest mniej zaszumiony niż dziennik logcat, ale też nieco trudniejszy do odczytania. Podczas przeglądania dzienników zdarzeń możesz wyszukiwać w tej sekcji określony identyfikator procesu (PID), aby sprawdzić, co robił dany proces. Podstawowy format to:timestamp PID TID log-level log-tag tag-values.

Poziomy logów obejmują:

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

 

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

Błędy ANR i zakleszczenia

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

Identyfikowanie aplikacji, które nie odpowiadają

Gdy aplikacja nie odpowiada w określonym czasie, zwykle z powodu zablokowania lub zajętości głównego wątku, system zamyka proces i zrzuca stos do /data/anr. Aby znaleźć przyczynę błędu ANR, wyszukaj w binarnym dzienniku zdarzeń ciąg znaków am_anr.

Możesz też wyszukać w logcat loguANR in znak ANR in, który zawiera więcej informacji o tym, co wykorzystywało procesor w momencie wystąpienia błędu ANR.

Znajdowanie zrzutów stosu

Często można znaleźć zrzuty stosu odpowiadające błędowi ANR. Upewnij się, że sygnatura czasowa i identyfikator PID w śladach maszyny wirtualnej pasują do błędu ANR, który analizujesz, a następnie sprawdź główny wątek procesu. Pamiętaj:

  • Wątek główny informuje tylko o tym, co robił w momencie wystąpienia błędu ANR, co może, ale nie musi odpowiadać prawdziwej przyczynie błędu ANR. (Stos w raporcie o błędzie może być niewinny. Coś innego mogło być zablokowane przez długi czas, ale nie na tyle długo, aby spowodować błąd ANR, zanim się odblokowało).
  • Może istnieć więcej niż jeden zestaw śladów stosu (VM TRACES JUST NOWVM TRACES AT LAST ANR). Upewnij się, że wyświetlasz odpowiednią sekcję.

Znajdowanie zakleszczeń

Zakleszczenia często najpierw pojawiają się jako ANR, ponieważ wątki się blokują. Jeśli zakleszczenie dotyczy serwera systemowego, mechanizm watchdog ostatecznie go zakończy, co spowoduje pojawienie się w dzienniku wpisu podobnego do tego: WATCHDOG KILLING SYSTEM PROCESS. Z punktu widzenia użytkownika urządzenie uruchamia się ponownie, chociaż technicznie jest to ponowne uruchomienie środowiska wykonawczego, a nie prawdziwe ponowne uruchomienie.

  • Podczas ponownego uruchamiania w trakcie działania serwer systemowy przestaje działać i jest ponownie uruchamiany. Użytkownik widzi, jak urządzenie wraca do animacji rozruchu.
  • Podczas ponownego uruchomienia następuje awaria jądra, a użytkownik widzi logo Google.

Aby znaleźć zakleszczenia, sprawdź sekcje śladów maszyny wirtualnej pod kątem wzorca wątku A oczekującego na coś, co jest w posiadaniu wątku B, który z kolei oczekuje na coś, co jest w posiadaniu wątku A.

Działania

Aktywność to komponent aplikacji, który zapewnia ekran, z którym użytkownicy wchodzą w interakcję, aby wykonać określone działanie, np. wybrać numer, zrobić zdjęcie, wysłać e-maila itp. Z punktu widzenia raportu o błędach aktywność to pojedyncza, skoncentrowana czynność, którą może wykonać użytkownik. Dlatego bardzo ważne jest zlokalizowanie aktywności, która była aktywna w momencie awarii. Działania (za pomocą ActivityManager) uruchamiają procesy, więc zlokalizowanie wszystkich zatrzymań i uruchomień procesu dla danego działania może również pomóc w rozwiązywaniu problemów.

Wyświetlanie aktywności w widoku tylko prezentacji

Aby wyświetlić historię działań, na których się skupiasz, wyszukaj am_focused_activity.

Rozpoczęcie procesu wyświetlania

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

Sprawdzanie, czy urządzenie nie jest w stanie thrashingu

Aby sprawdzić, czy urządzenie wykonuje nadmierną liczbę operacji, poszukaj nienormalnego wzrostu aktywności w okolicach am_proc_diedam_proc_start w krótkim czasie.

Pamięć

Urządzenia z Androidem często mają ograniczoną pamięć fizyczną, dlatego zarządzanie pamięcią RAM jest kluczowe. Raporty o błędach zawierają kilka wskaźników niskiego poziomu pamięci, a także zrzut stanu, który zawiera migawkę pamięci.

Określanie małej ilości pamięci

Niewystarczająca ilość pamięci może powodować niestabilność systemu, ponieważ zabija on niektóre procesy, aby zwolnić pamięć, ale nadal uruchamia inne procesy. Aby wyświetlić dowody potwierdzające niski poziom pamięci, sprawdź w binarnym dzienniku zdarzeń występowanie wpisów am_proc_diedam_proc_start.

Mała ilość pamięci może również spowalniać przełączanie zadań i uniemożliwiać powrót do poprzedniego zadania (ponieważ zadanie, do którego użytkownik próbował wrócić, zostało zamknięte). Jeśli program uruchamiający został zamknięty, uruchomi się ponownie, gdy użytkownik dotknie przycisku strony głównej, a w logach pojawi się informacja o ponownym załadowaniu treści przez program uruchamiający.

Wyświetlanie wskaźników historycznych

Wpis am_low_memory w binarnym dzienniku zdarzeń wskazuje, że ostatni proces z pamięci podręcznej został zakończony. Następnie system zacznie zamykać usługi.

Wyświetlanie wskaźników thrashingu

Inne wskaźniki nadmiernego obciążenia systemu (stronicowanie, bezpośrednie odzyskiwanie pamięci itp.) to kswapd, kworkermmcqd zużywające cykle. (Pamiętaj, że zbierany raport o błędach może wpływać na wskaźniki thrashingu).

Podobną migawkę pamięci mogą zawierać logi ANR.

Wykonaj zrzut pamięci

Migawka pamięci to zrzut stanu, który zawiera listę uruchomionych procesów Java i natywnych (więcej informacji znajdziesz w sekcji Wyświetlanie ogólnych przydziałów pamięci). Pamiętaj, że migawka przedstawia stan systemu w określonym momencie. Przed jej wykonaniem system mógł być w lepszej (lub gorszej) kondycji.

Nadawanie

Aplikacje generują transmisje, aby wysyłać zdarzenia w ramach bieżącej aplikacji lub do innej aplikacji. Odbiorniki transmisji subskrybują określone komunikaty (za pomocą filtrów), co umożliwia im słuchanie transmisji i odpowiadanie na nie. Raporty o błędach zawierają informacje o wysłanych i niewysłanych transmisjach, a także zrzut systemowy wszystkich odbiorników nasłuchujących konkretną transmisję.

Wyświetlanie historycznych transmisji

Wiadomości historyczne to te, które zostały już wysłane i są wymienione w odwrotnej kolejności chronologicznej.

Sekcja Podsumowanie zawiera omówienie ostatnich 300 transmisji na pierwszym planie i 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 odbiorniki każdej transmisji. Odbiorniki, które mają:

  • Wpisy BroadcastFilter są rejestrowane w czasie działania i wysyłane tylko do już działających procesów.
  • Wpisy ResolveInfo są rejestrowane za pomocą wpisów w pliku manifestu. Usługa ActivityManager rozpoczyna proces dla każdego ResolveInfo, jeśli nie jest on jeszcze uruchomiony.

Wyświetlanie aktywnych transmisji

Aktywne transmisje to te, które nie zostały jeszcze wysłane. Duża liczba w kolejce oznacza, że system nie może wystarczająco szybko wysyłać transmisji.

Wyświetlanie słuchaczy transmisji

Aby wyświetlić listę odbiorców nasłuchujących transmisji, sprawdź tabelę Receiver Resolver w dumpsys activity broadcasts. Poniższy przykład pokazuje wszystkich odbiorców nasłuchujących USER_PRESENT.

Monitorowanie rywalizacji

Rejestrowanie rywalizacji o monitor może czasami wskazywać rzeczywistą rywalizację o monitor, ale najczęściej oznacza, że system jest tak obciążony, że wszystko działa wolniej. W dzienniku systemowym lub dzienniku zdarzeń mogą być rejestrowane długie zdarzenia monitora 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ż zachodzić w tle, gdy aplikacja wczytuje plik DEX, który nie został jeszcze skompilowany. W takim przypadku nie zobaczysz logowania finsky ani installd.

Narracja

Ustalenie przebiegu problemu (jak się zaczął, co się stało, jak zareagował system) wymaga solidnej osi czasu zdarzeń. Informacje w raporcie o błędach możesz wykorzystać do synchronizowania osi czasu w wielu logach i określania dokładnej sygnatury czasowej raportu o błędach.

Harmonogramy synchronizacji

Raport o błędzie odzwierciedla wiele równoległych osi czasu: dziennik systemowy, dziennik zdarzeń, dziennik jądra i wiele specjalistycznych osi czasu dotyczących transmisji, statystyk baterii itp. Niestety osie czasu są często raportowane przy użyciu różnych podstaw czasowych.

Sygnatury czasowe systemu i dziennika zdarzeń są podawane w tej samej strefie czasowej co użytkownik (podobnie jak większość innych sygnatur czasowych). Na przykład gdy użytkownik naciśnie przycisk strony głównej, w logu systemowym pojawi się:

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ń podaje:

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 bazy czasu, oznaczając elementy logu sekundami od zakończenia działania programu rozruchowego. Aby zarejestrować tę skalę czasową w przypadku innych skal, wyszukaj komunikaty suspend exitsuspend entry:

<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

Dzienniki jądra mogą nie zawierać informacji o czasie, gdy urządzenie jest w stanie wstrzymania, dlatego należy rejestrować dziennik w częściach między wiadomościami o wejściu w stan wstrzymania i wyjściu z niego. Dodatkowo dzienniki jądra korzystają ze strefy czasowej UTC i muszą być dostosowane do strefy czasowej użytkownika.

Określanie czasu raportu o błędzie

Aby określić, kiedy wygenerowano raport o błędzie, najpierw sprawdź dziennik systemowy (Logcat) pod kątem dumpstate: begin:

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

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

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

Aby powiązać te 2 zdarzenia, cofnij się w czasie, pamiętając o zastrzeżeniach wymienionych w sekcji Synchronizowanie osi czasu. Po rozpoczęciu tworzenia raportu o błędzie dzieje się wiele rzeczy, ale większość z nich nie jest zbyt przydatna, ponieważ samo tworzenie raportu o błędzie znacznie obciąża system.

Moc

Dziennik zdarzeń zawiera stan zasilania ekranu, gdzie 0 oznacza wyłączony ekran, 1 – włączony ekran, a 2 – zakończenie działania blokady klawiatury.

Raporty o błędach zawierają też statystyki dotyczące blokad wybudzania, czyli mechanizmu używanego przez deweloperów aplikacji do informowania, że aplikacja wymaga, aby urządzenie pozostawało włączone. (Więcej informacji o blokadach uśpienia znajdziesz w sekcjach PowerManager.WakeLockUtrzymywanie procesora włączonego).

Statystyki dotyczące łącznego czasu trwania blokady uśpienia śledzą tylko czas, w którym blokada uśpienia rzeczywiście utrzymuje urządzenie w stanie aktywności, i nie obejmują czasu, gdy ekran jest włączony. Jeśli jednocześnie jest aktywnych kilka blokad uśpienia, czas trwania blokady uśpienia jest rozdzielany między te blokady.

Aby uzyskać więcej informacji o stanie zasilania, użyj Battery Historian, czyli narzędzia open source Google do analizowania zużycia baterii na podstawie plików raportu o błędach Androida.

Pakiety

Sekcja DUMP OF SERVICE package zawiera wersje aplikacji (i 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, oom_adj itp. Szczegółowe informacje o tym, jak Android zarządza procesami, znajdziesz w artykule Procesy i wątki.

Określanie czasu działania procesu

Sekcja procstats zawiera pełne statystyki dotyczące czasu działania procesów i powiązanych usług. Aby uzyskać szybkie podsumowanie w formacie czytelnym dla człowieka, 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 przy różnych priorytetach i zużycie pamięci RAM w formacie min-średnia-maksymalna PSS/min-średnia-maksymalna USS.

Przyczyny działania procesu

W sekcji dumpsys activity processes znajdziesz listę wszystkich aktualnie działających procesów uporządkowanych według wyniku oom_adj (Android określa ważność procesu, przypisując mu wartość oom_adj, która może być dynamicznie aktualizowana przez ActivityManager). Dane wyjściowe są podobne do migawki pamięci, ale zawierają dodatkowe informacje o tym, co powoduje działanie procesu. W poniższym przykładzie pogrubione wpisy wskazują, że proces gms.persistent jest uruchomiony z priorytetem vis (widocznym), ponieważ proces systemowy jest powiązany z jego NetworkLocationService.

Skanowania

Aby zidentyfikować aplikacje, które wykonują zbyt wiele skanów Bluetooth Low Energy (BLE):

  • Znajdź wiadomości w dzienniku dla 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 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.

  • Sprawdź nazwę pakietu w Google Play, aby zidentyfikować aplikację, która jest za to odpowiedzialna: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 przypisuje te działania do aplikacji, która je zainicjowała. Więcej informacji znajdziesz w artykule Skanowanie Bluetooth Low Energy (LE).