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

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

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

ЛогКэт

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

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

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

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

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

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

ANR и тупики

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

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

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

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

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

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

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

Найти тупики

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

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

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

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

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

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

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

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

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

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

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

Память

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

Определить низкий уровень памяти

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

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

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

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

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

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

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

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

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

Трансляции

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

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

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

Раздел сводки представляет собой обзор последних 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. В этом случае сообщения от приложения магазина Google Play ( 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 .)

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

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

Пакеты

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

Процессы

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

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

Раздел procstats содержит полную статистику о том, как долго работают процессы и связанные с ними службы. Для быстрого, понятного человеку резюме выполните поиск AGGREGATED OVER , чтобы просмотреть данные за последние три или 24 часа, затем выполните поиск Summary: чтобы просмотреть список процессов, как долго эти процессы работали с различными приоритетами, и их использование оперативной памяти в формате мин-среднее-макс PSS/мин-среднее-макс 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 и связывает эти действия с инициирующим приложением. Подробности см. в разделе Low Energy (LE) и Bluetooth scans .