Читать отчеты об ошибках

Ошибки — неотъемлемая часть любой разработки, и отчёты об ошибках критически важны для выявления и решения проблем. Все версии Android поддерживают сбор отчётов об ошибках с помощью Android Debug Bridge (adb) ; версии Android 4.2 и выше поддерживают опцию разработчика для сбора отчётов об ошибках и их распространения по электронной почте, через Диск и т. д.

Отчёты об ошибках Android содержат данные dumpsys , dumpstate и logcat в текстовом формате (.txt), что позволяет легко искать нужную информацию. В следующих разделах подробно описаны компоненты отчётов об ошибках, описаны распространённые проблемы, а также даны полезные советы и команды grep для поиска журналов, связанных с этими ошибками. Большинство разделов также содержат примеры использования команды grep и её вывода и/или вывода dumpsys .

Логкат

Журнал logcat представляет собой строковый дамп всей информации logcat . Системная часть зарезервирована для фреймворка и имеет более длинную историю, чем основная , содержащая всё остальное. Каждая строка обычно начинается с timestamp UID PID TID log-level , хотя в старых версиях Android UID может отсутствовать.

Просмотреть журнал событий

Этот журнал содержит строковые представления сообщений в двоичном формате. Он менее запутан, чем журнал logcat , но его немного сложнее читать. При просмотре журналов событий вы можете выполнить поиск в этом разделе по идентификатору конкретного процесса (PID), чтобы узнать, что делал процесс. Базовый формат: timestamp PID TID log-level log-tag tag-values .

Уровни журнала включают в себя следующее:

  • V: многословный
  • D: отладка
  • Я: информация
  • В: предупреждение
  • E: ошибка

Другие полезные теги журнала событий см. в /services/core/java/com/android/server/EventLogTags.logtags .

ANR и тупики

Отчеты об ошибках помогут вам определить причины ошибок «Приложение не отвечает» (ANR) и событий взаимоблокировки.

Определите неотвечающие приложения

Когда приложение не отвечает в течение определённого времени, обычно из-за заблокированного или занятого основного потока, система завершает процесс и сбрасывает стек в /data/anr . Чтобы определить причину ошибки ANR, выполните команду grep для am_anr в двоичном журнале событий.

Вы также можете выполнить grep на предмет ANR in в журнале logcat , который содержит дополнительную информацию о том, что использовало ресурсы ЦП во время возникновения ANR.

Найти трассировки стека

Часто можно обнаружить трассировки стека, соответствующие ANR. Убедитесь, что временная метка и PID в трассировках виртуальной машины соответствуют ANR, которую вы исследуете, а затем проверьте основной поток процесса. Обратите внимание:

  • Основной поток сообщает только о том, что поток делал во время возникновения ANR, что может соответствовать или не соответствовать истинной причине ANR. (Стек в отчёте об ошибке может быть невинным; что-то ещё могло зависнуть на долгое время, но недостаточно долго для возникновения ANR, прежде чем отсоединиться.)
  • Может существовать несколько наборов трассировок стека ( VM TRACES JUST NOW и VM TRACES AT LAST ANR ). Убедитесь, что вы просматриваете нужный раздел.

Найти тупики

Взаимоблокировки часто сначала отображаются как ошибки ANR, связанные с зависанием потоков. Если взаимоблокировка затрагивает системный сервер, сторожевой таймер в конечном итоге завершает его, что приводит к появлению в журнале записи, похожей на: WATCHDOG KILLING SYSTEM PROCESS . С точки зрения пользователя устройство перезагружается, хотя технически это перезапуск среды выполнения, а не настоящая перезагрузка.

  • При перезапуске во время выполнения системный сервер останавливается и перезапускается; пользователь видит, как устройство возвращается к анимации загрузки.
  • При перезагрузке происходит сбой ядра; пользователь видит, что устройство возвращается к логотипу загрузки Google.

Чтобы обнаружить взаимоблокировки, проверьте разделы трассировки виртуальной машины на наличие шаблона, в котором поток A ожидает чего-то, удерживаемого потоком B, который, в свою очередь, ожидает чего-то, удерживаемого потоком A.

Деятельность

Активность — это компонент приложения, предоставляющий пользователю экран, с которым он взаимодействует, чтобы выполнить какие-либо действия, например, набрать номер, сделать фотографию, отправить электронное письмо и т. д. С точки зрения отчёта об ошибке, активность — это одно определённое действие, которое может выполнить пользователь, поэтому очень важно определить, какое именно действие было в фокусе во время сбоя. Активности (через ActivityManager) запускают процессы, поэтому определение всех остановок и запусков процессов для данной активности также может помочь в устранении неполадок.

Просмотреть целевые мероприятия

Чтобы просмотреть историю целевых действий, выполните поиск по запросу am_focused_activity .

Просмотр процесса начинается

Чтобы просмотреть историю запусков процессов, выполните поиск по запросу Start proc .

Определите, работает ли устройство вхолостую

Чтобы определить, пробуксовывает ли устройство, проверьте, не наблюдается ли аномальное увеличение активности в районе am_proc_died и am_proc_start за короткий промежуток времени.

Память

Поскольку устройства Android часто имеют ограниченный объём физической памяти, управление оперативной памятью (ОЗУ) критически важно. Отчёты об ошибках содержат несколько индикаторов нехватки памяти, а также дамп-снимок памяти.

Определить недостаток памяти

Нехватка памяти может привести к перегрузкам системы, поскольку она завершает некоторые процессы для освобождения памяти, но продолжает запускать другие. Чтобы получить подтверждающие доказательства нехватки памяти, проверьте концентрацию записей am_proc_died и am_proc_start в двоичном журнале событий.

Недостаток памяти также может замедлить переключение задач и помешать попыткам вернуться к предыдущей задаче (поскольку задача, к которой пользователь пытался вернуться, была закрыта). Если лаунчер был закрыт, он перезапускается при нажатии пользователем кнопки «Домой», и в журналах отображается, что лаунчер перезагружает своё содержимое.

Просмотр исторических показателей

Запись am_low_memory в двоичном журнале событий указывает на завершение последнего кэшированного процесса. После этого система начинает завершать службы.

Просмотреть индикаторы обмолота

К другим показателям перегрузки системы (подкачка страниц, прямое восстановление и т. д.) относятся циклы потребления kswapd , kworker и mmcqd . (Имейте в виду, что собираемые отчеты об ошибках могут влиять на показатели перегрузки.)

Аналогичный снимок памяти можно получить с помощью журналов ANR.

Получите снимок памяти

Снимок памяти — это дамп-стейт, содержащий список запущенных процессов Java и нативных процессов (подробнее см. в разделе Просмотр общего распределения памяти ). Имейте в виду, что снимок отображает состояние только на конкретный момент времени; до снимка система могла быть в лучшем (или худшем) состоянии.

Трансляции

Приложения генерируют широковещательные сообщения для отправки событий внутри текущего приложения или в другое приложение. Приёмники широковещательных сообщений подписываются на определённые сообщения (через фильтры), что позволяет им как прослушивать, так и отвечать на широковещательные сообщения. Отчёты об ошибках содержат информацию об отправленных и неотправленных широковещательных сообщениях, а также системную базу данных всех приёмников, прослушивающих определённую широковещательную рассылку.

Посмотреть исторические трансляции

Исторические трансляции — это те, которые уже были отправлены, перечисленные в обратном хронологическом порядке.

Раздел сводки представляет собой обзор последних 300 трансляций в активном режиме и последних 300 фоновых трансляций.

Раздел «Подробности» содержит полную информацию о последних 50 трансляциях в активном режиме и 50 фоновых трансляциях, а также о приемниках каждой трансляции. Приемники, которые имеют:

  • Записи BroadcastFilter регистрируются во время выполнения и отправляются только уже запущенным процессам.
  • Записи ResolveInfo регистрируются через записи манифеста. ActivityManager запускает процесс для каждой ResolveInfo , если она ещё не запущена.

Посмотреть активные трансляции

Активные рассылки — это те, которые ещё не были отправлены. Большое количество сообщений в очереди означает, что система не может отправлять рассылки достаточно быстро.

Посмотреть слушателей трансляции

Чтобы просмотреть список приёмников, прослушивающих широковещательную рассылку, проверьте таблицу Receiver Resolver в dumpsys activity broadcasts . В следующем примере показаны все приёмники, прослушивающие USER_PRESENT .

Мониторить конкуренцию

Журналирование конфликтов на мониторе иногда может указывать на реальный конфликт, но чаще всего указывает на то, что система настолько загружена, что всё замедляется. Вы можете увидеть длинные события мониторинга, зарегистрированные ART в системном журнале или журнале событий.

В системном журнале: 

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

В журнале событий: 

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]

Фоновая компиляция

Компиляция может быть затратной и нагружать устройство.

Компиляция может происходить в фоновом режиме во время загрузки обновлений Google Play Store. В этом случае сообщения от приложения Google Play Store ( finsky ) и installd появляются раньше сообщений dex2oat .

Компиляция также может происходить в фоновом режиме, когда приложение загружает ещё не скомпилированный dex-файл. В этом случае вы не увидите журналы finsky и installd .

Повествование

Для описания проблемы (как она возникла, что произошло, как отреагировала система) требуется чёткая хронология событий. Информацию из отчёта об ошибке можно использовать для синхронизации временных шкал нескольких журналов и определения точной временной метки отчёта об ошибке.

Синхронизация временных шкал

Отчет об ошибке отражает несколько параллельных временных шкал: системный журнал, журнал событий, журнал ядра и несколько специализированных временных шкал для трансляций, статистики батареи и т. д. К сожалению, временные шкалы часто сообщаются с использованием разных временных баз.

Временные метки системы и журнала событий находятся в том же часовом поясе, что и пользователь (как и большинство других временных меток). Например, когда пользователь нажимает кнопку «Домой», в системном журнале отображается следующее: 

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

Для того же действия журнал событий сообщает: 

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

Журналы ядра ( dmesg ) используют другую временную базу, отмечая записи журнала секундами с момента завершения загрузки. Чтобы сопоставить эту временную шкалу с другими шкалами, найдите сообщения о выходе из режима приостановки и входе в режим приостановки : 

<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

Поскольку журналы ядра могут не содержать времени в режиме ожидания, следует регистрировать журнал по частям между сообщениями о входе и выходе из режима ожидания. Кроме того, журналы ядра используют часовой пояс UTC и должны быть скорректированы в соответствии с часовым поясом пользователя.

Определить время сообщения об ошибке

Чтобы определить, когда был создан отчет об ошибке, сначала проверьте системный журнал (Logcat) на наличие dumpstate: begin : 

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

Затем проверьте временные метки журнала ядра ( dmesg ) на наличие сообщения Starting service 'bugreport' : 

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

Проведите обратную корреляцию двух событий, учитывая оговорки, упомянутые в разделе «Синхронизация временных шкал» . Хотя после создания отчёта об ошибке происходит много событий, большая их часть не очень полезна, поскольку сам процесс создания отчёта об ошибке существенно нагружает систему.

Власть

Журнал событий содержит информацию о состоянии питания экрана, где 0 — экран выключен, 1 — экран включен, а 2 — блокировка клавиатуры отключена.

Отчеты об ошибках также содержат статистику о блокировках сна — механизме, используемом разработчиками приложений для указания приложению необходимости поддерживать устройство включенным. (Подробнее о блокировках сна см. в разделах PowerManager.WakeLock и Keep the CPU on .)

Агрегированная статистика длительности блокировки пробуждения учитывает только время, в течение которого блокировка пробуждения фактически поддерживает устройство в активном состоянии, и не учитывает время с включённым экраном. Кроме того, если одновременно удерживается несколько блокировок пробуждения, длительность блокировки распределяется между ними.

Для получения дополнительной информации о состоянии заряда батареи используйте Battery Historian — инструмент Google с открытым исходным кодом для анализа потребления заряда батареи с использованием файлов отчетов об ошибках Android.

Пакеты

Раздел DUMP OF SERVICE package содержит версии приложений (и другую полезную информацию).

Процессы

Отчеты об ошибках содержат огромный объем данных о процессах, включая время запуска и остановки, продолжительность выполнения, связанные службы, оценку oom_adj и т. д. Подробную информацию об управлении процессами в Android см. в разделе Процессы и потоки .

Определить время выполнения процесса

Раздел procstats содержит полную статистику о продолжительности работы процессов и связанных с ними служб. Для быстрого и удобного просмотра сводки выполните поиск по запросу AGGREGATED OVER , чтобы просмотреть данные за последние три или 24 часа, а затем выполните поиск по Summary: чтобы просмотреть список процессов, их продолжительность с различными приоритетами и использование ими оперативной памяти в формате min-medium-max PSS/min-medium-max USS.

Причины запуска процесса

В разделе dumpsys activity processes перечислены все текущие запущенные процессы, упорядоченные по значению oom_adj (Android указывает важность процесса, присваивая ему значение oom_adj , которое может динамически обновляться ActivityManager). Вывод аналогичен снимку памяти , но включает дополнительную информацию о причине запуска процесса. В примере ниже выделенные жирным шрифтом записи указывают на то, что процесс gms.persistent выполняется с приоритетом vis (видимый), поскольку системный процесс привязан к своему NetworkLocationService .

Сканирование

Чтобы определить приложения, выполняющие чрезмерное сканирование Bluetooth Low Energy (BLE), выполните следующие действия:

  • Найти сообщения журнала для BluetoothLeScanner : 
    $ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
  • Найдите PID в сообщениях журнала. В этом примере «24840» и «24851» — это PID (идентификатор процесса) и TID (идентификатор потока).
  • Найдите приложение, связанное с PID:
    PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}

    В этом примере имя пакета — com.badapp .

  • Найдите имя пакета в Google Play, чтобы определить ответственное приложение: https://play.google.com/store/apps/details?id=com.badapp .

Примечание : На устройствах под управлением Android 7.0 система собирает данные для сканирования BLE и связывает эти действия с инициирующим приложением. Подробнее см. в разделе «Сканирование с низким энергопотреблением (LE) и Bluetooth» .