Cómo leer informes de errores

Los errores son una realidad en cualquier tipo de desarrollo, y los informes de errores son muy importantes para identificar y resolver problemas. Todas las versiones de Android admiten la captura de informes de errores con Android Debug Bridge (adb); las versiones 4.2 y posteriores de Android admiten la Opción para desarrolladores que permite tomar informes de errores y compartirlos por correo electrónico, Drive, etc.

Los informes de errores de Android contienen datos dumpsys, dumpstate y logcat en formato de texto (.txt), lo que te permite buscar fácilmente contenido específico. En las siguientes secciones, se detallan los componentes de los informes de errores, se describen problemas comunes y se brindan sugerencias útiles y comandos grep para encontrar registros asociados con esos errores. En la mayoría de las secciones, también se incluyen ejemplos para el comando y la salida grep, o la salida dumpsys.

Logcat

El registro logcat es un volcado basado en strings de toda la información de logcat. La parte de system está reservada para el marco de trabajo y tiene un historial más largo que main, que contiene todo lo demás. Cada línea comienza con timestamp PID TID log-level.

Visualización del registro de acontecimientos

Este registro contiene representaciones de strings de mensajes de registro con formato binario. Es menos complejo que el registro logcat, pero también un poco más difícil de leer. Cuando visualizas registros de acontecimientos, puedes buscar en esta sección un ID de proceso (PID) específico con el objetivo de ver lo que estuvo realizando un proceso. El formato básico es timestamp PID TID log-level log-tag tag-values.

Los niveles de registro incluyen lo siguiente:

  • V: Detallado
  • D: Depuración
  • I: Información
  • W: Advertencia
  • E: Error

 

Para ver otras etiquetas de registros de acontecimientos útiles, consulta /services/core/java/com/android/server/EventLogTags.logtags.

Interbloqueos y ANR

Los informes de errores pueden ayudarte a identificar qué causa los errores de Aplicación no responde (ANR) y eventos de interbloqueo.

Identificación de apps que no responden

Cuando una aplicación no responde dentro de un tiempo determinado, generalmente se debe a que un subproceso principal está ocupado o bloqueado y, entonces, el sistema detiene el proceso y descarga la pila en /data/anr. Para descubrir la causa de un ANR, realiza una búsqueda grep de am_anr en el registro de acontecimientos binarios.

También puedes realizar una búsqueda grep de ANR in en el registro logcat, que contiene más información sobre lo que estaba usando la CPU al momento del ANR.

Cómo encontrar seguimientos de pila

A menudo, puedes encontrar seguimientos de pila que corresponden a un ANR. Asegúrate de que la marca de tiempo y el PID de los seguimientos de VM coincidan con el ANR que estés investigando. Luego, verifica el subproceso principal del proceso. Ten en cuenta lo siguiente:

  • El subproceso principal solo te dice qué estaba haciendo el subproceso al momento del ANR, lo que puede corresponder o no a la verdadera causa de este. (La pila del informe de errores puede ser inocente; otra cosa haber estado atascada durante mucho tiempo, pero no lo suficiente para generar un error ANR, antes de deshacerse).
  • Puede existir más de un conjunto de seguimiento de pila (VM TRACES JUST NOW y VM TRACES AT LAST ANR). Asegúrate de estar viendo la sección correcta.

Cómo buscar interbloqueos

Los interbloqueos suelen aparecer en principio como ANR cuando se atascan subprocesos. Si el interbloqueo afecta al servidor del sistema, el guardián lo finalizará y provocará una entrada en el registro similar a WATCHDOG KILLING SYSTEM PROCESS. Desde la perspectiva del usuario, se reinicia el dispositivo, aunque técnicamente es un reinicio del tiempo de ejecución en lugar de un verdadero reinicio.

  • En un reinicio de tiempo de ejecución, se apaga y se reinicia el servidor del sistema; el usuario ve que el dispositivo regresa a la animación de inicio.
  • En un reinicio, falla el kernel; el usuario ve que el dispositivo regresa al logotipo de inicio de Google.

Para encontrar interbloqueos, revisa las secciones de seguimiento de VM a fin de encontrar un patrón de subproceso A que espera un objeto retenido por el subproceso B, que a su vez está esperando un objeto retenido por el subproceso A.

Actividades

Un objeto Activity es un componente de la aplicación que proporciona una pantalla con la que interactúan los usuarios para marcar un número, tomar una foto, enviar un correo electrónico, etc. Desde la perspectiva del informe de errores, un objeto Activity es una actividad única y específica que puede realizar un usuario. Durante una falla, es muy importante ver qué actividad que estaba en foco. Dado que los objetos Activity ejecutan procesos (mediante ActivityManager), ubicar todos los inicios y procesos de una actividad determinada también puede ayudar a solucionar problemas.

Cómo ver las actividades enfocadas

Para ver un historial de actividades enfocadas, busca am_focused_activity.

Cómo ver los inicios de procesos

Para ver un historial de inicios de procesos, busca Start proc.

¿El dispositivo realiza una hiperpaginación?

Para determinar si el dispositivo realiza una hiperpaginación, verifica si hay un aumento anormal de la actividad alrededor de am_proc_died y am_proc_start en un período corto.

Memoria

Debido a que los dispositivos Android suelen tener memoria física limitada, es fundamental administrar la memoria de acceso aleatorio (RAM). Los informes de errores contienen varios indicadores de memoria baja, así como un dumpstate que proporciona una instantánea de la memoria.

Cómo identificar memoria baja

La memoria baja puede hacer que falle el sistema, ya que elimina algunos procesos para liberar memoria, pero continúa iniciando otros. Para ver la evidencia que compruebe la memoria baja, verifica las concentraciones de las entradas am_proc_died y am_proc_start en el registro de acontecimientos binarios.

La memoria baja también puede ralentizar el cambio de tareas y frustrar los intentos de retorno (porque se eliminó la tarea a la que el usuario intenta regresar). Si se cerró el selector, se reinicia cuando el usuario toca el botón de inicio y los registros muestran que el selector vuelve a cargar su contenido.

Cómo ver indicadores históricos

La entrada am_low_memory del registro de acontecimientos binarios indica que finalizó el último proceso en caché. Después de esto, el sistema comienza a cerrar servicios.

Cómo ver indicadores de hiperpaginación

Otros indicadores de hiperpaginación del sistema (paginación, recuperación directa, etc.) incluyen los ciclos de consumo kswapd, kworker y mmcqd. (Ten en cuenta que el informe de errores recopilado puede influir en los indicadores de hiperpaginación).

Los registros de ANR pueden proporcionar una instantánea de memoria similar.

Cómo obtener una instantánea de memoria

La instantánea de memoria es un dumpstate que enumera los procesos nativos y de Java en ejecución (para obtener más información, consulta Cómo ver asignaciones de memoria generales). Ten en cuenta que la instantánea solo muestra el estado en un momento específico en el tiempo; el sistema podría haber estado en mejor (o peor) estado antes de ella.

Transmisiones

Las aplicaciones generan transmisiones con el objetivo de enviar eventos dentro de la aplicación actual o en otra aplicación. Los receptores de transmisión se suscriben a mensajes específicos (mediante filtros), lo que les permite escuchar y responder una transmisión. Los informes de errores contienen información sobre transmisiones enviadas y no enviadas, además de un dumpsys de todos los receptores que escuchan una transmisión específica.

Cómo ver transmisiones históricas

Las transmisiones históricas son aquellas que ya se enviaron, enumeradas en orden cronológico inverso.

La sección summary es una descripción general de las últimas 300 transmisiones en primer plano y las últimas 300 en segundo plano.

La sección detail contiene información completa de las últimas 50 transmisiones en primer plano y las últimas 50 en segundo plano, así como los receptores de cada transmisión. Receptores que tienen lo siguiente:

  • Las entradas BroadcastFilter se registran en el tiempo de ejecución y se envían solo a los procesos que ya están en curso.
  • La entrada ResolveInfo se registra mediante entradas de manifiesto. ActivityManager inicia el proceso para cada ResolveInfo si aún no se está ejecutando.

Cómo ver transmisiones activas

Las transmisiones activas son aquellas que todavía no se enviaron. Un número alto en la cola significa que el sistema no puede despachar las transmisiones lo suficientemente rápido como para mantenerse al día.

Cómo ver objetos de escucha de transmisión

Para ver una lista de receptores que son objetos de escucha de una transmisión, revisa la tabla Agente de resolución del receptor en las dumpsys activity broadcasts. En el siguiente ejemplo, se muestran todos los receptores que actúan como agente de escucha para USER_PRESENT.

Contención de monitor

El registro de contención de monitor a veces puede indicar la contención real del monitor, pero a menudo indica que el sistema está tan ocupado que todo se ejecuta más lento. Es posible que veas eventos de monitoreo de larga duración registrados por ART en el sistema o en el registro de acontecimientos.

En el registro del sistema:

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

En el registro de acontecimientos:

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]

Compilación en segundo plano

La compilación puede consumir muchos recursos y ralentizar el dispositivo.

La compilación puede producirse en segundo plano cuando se descargan actualizaciones de Google Play Store. En este caso, los mensajes de la app de Google Play Store (finsky) e installd aparecen antes que los mensajes de dex2oat.

La compilación también puede producirse en segundo plano cuando una aplicación está cargando un archivo dex que todavía no se compiló. En ese caso, no verás los registros finsky ni installd.

Narración

Establecer la narración de un problema (cómo comenzó, qué sucedió y cómo reaccionó el sistema) requiere una sólida línea de tiempo de eventos. Puedes usar los datos del informe de errores para sincronizar los cronogramas de varios registros y determinar la marca de tiempo exacta del informe de errores.

Cómo sincronizar líneas de tiempo

Un informe de errores refleja múltiples líneas de tiempo paralelas: registro del sistema, registro de acontecimientos, registro del núcleo y múltiples líneas de tiempo especializadas para transmisiones, estadísticas de batería, etc. Desafortunadamente, las líneas de tiempo a menudo se informan con diferentes bases de tiempo.

Las marcas de tiempo del registro de acontecimientos y del sistema están en la misma zona horaria que el usuario (como la mayoría de las otras marcas de tiempo). Por ejemplo, cuando el usuario presiona el botón de inicio, el registro del sistema informa lo siguiente:

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

Para la misma acción, el registro de acontecimientos informa lo siguiente:

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

Los registros kernel (dmesg) usan una base de tiempo diferente y etiquetan los elementos de registro con segundos desde que se completa el bootloader. Para registrar esta escala de tiempo en otras escalas, busca los mensajes suspend exit y suspended 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

Debido a que es posible que estos registros no incluyan el tiempo mientras están en suspensión, deberías registrar de a partes el registro entre los mensajes de suspensión y de salida. Además, los registros kernel usan la zona horaria UTC y deben ajustarse a la del usuario.

Cómo identificar el tiempo de los informes de errores

Para determinar cuándo se tomó un informe de errores, primero revisa el registro del sistema (Logcat) de dumpstate: begin:

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

Luego, verifica las marcas de tiempo del registro kernel (dmesg) para el mensaje Starting service 'bugreport':

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

Trabaja hacia atrás para correlacionar los dos eventos, pero ten en cuenta las advertencias mencionadas en la sección Sincronización de líneas de tiempo. Si bien hay muchas novedades después de iniciado el informe de errores, la mayoría de las actividades no son muy útiles, ya que el informe carga el sistema de manera sustancial.

Encendido

El registro de acontecimientos contiene el estado de encendido de la pantalla, donde 0 es apagado, 1 es encendido y 2 es para el bloqueo del teclado.

Los informes de errores también contienen estadísticas sobre los bloqueos de activación, un mecanismo que usan los desarrolladores de aplicaciones para indicar que su aplicación necesita que el dispositivo permanezca encendido. (Si quieres obtener más información sobre los bloqueos de activación, consulta PowerManager.WakeLock y Cómo mantener la CPU encendida).

Las estadísticas acumuladas sobre la duración del bloqueo de activación solo registran el tiempo que un bloqueo de activación es responsable de mantener el dispositivo activo y no incluyen el tiempo con la pantalla encendida. Además, si se producen varios bloqueos de activación simultáneos, el tiempo de duración del bloqueo de activación se distribuirá entre esos bloqueos de activación.

Para obtener más ayuda sobre cómo visualizar el estado de encendido, usa Battery Historian, una herramienta de código abierto de Google para analizar qué elementos consumen la batería mediante archivos de informes de errores de Android.

Paquetes

El paquete DUMP OF SERVICE contiene versiones de la aplicación (y demás información útil).

Procesos

Los informes de errores contienen una gran cantidad de datos para procesos, incluidos el tiempo de inicio y finalización, la duración del tiempo de ejecución, los servicios asociados, la puntuación de oom_adj, etc. Si quieres obtener información detallada sobre cómo Android gestiona los procesos, consulta la sección Procesos y subprocesos.

Cómo determinar el tiempo de ejecución del proceso

En la sección procstats, encontrarás estadísticas completas sobre el tiempo en que se estuvieron ejecutando los procesos y los servicios asociados. Para obtener un resumen rápido y legible, busca AGGREGATED OVER a fin de ver los datos de las últimas tres o 24 horas. Luego, busca Summary: para ver la lista de procesos, cuánto tiempo han transcurrido esos procesos con diversas prioridades y su uso de RAM con el formato min-average-max PSS/min-average-max USS.

¿Por qué se está ejecutando un proceso?

En la sección dumpsys activity processes, se enumeran todos los procesos en ejecución ordenados por la puntuación de oom_adj (Android indica la importancia del proceso al asignarle un valor oom_adj, que ActivityManager puede actualizar de forma dinámica). El resultado es similar al de una instantánea de memoria, pero incluye información adicional sobre qué está causando la ejecución del proceso. En el siguiente ejemplo, las entradas en negrita indican que el proceso gms.persistent se ejecuta con prioridad vis (visible) porque el proceso del sistema está vinculado a su NetworkLocationService.

Análisis

Sigue estos pasos para identificar las aplicaciones que realizan análisis excesivos de Bluetooth de bajo consumo (BLE):

  • Busca mensajes de registro de BluetoothLeScanner:
        $ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
        07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
        
  • Encuentra el PID en los mensajes de registro. En este ejemplo, "24840" y "24851" son PID (ID de proceso) y TID (ID de subproceso).
  • Encuentra la aplicación asociada con el PID:
        PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}
        

    En este ejemplo, el nombre del paquete es com.badapp.

  • Busca el nombre del paquete en Google Play para identificar la aplicación responsable: https://play.google.com/store/apps/details?id=com.badapp.

Nota: En los dispositivos que ejecutan Android 7.0, el sistema recopila datos para análisis de BLE y los asocia a la aplicación de inicio. Para obtener más información, consulta la sección Análisis de bajo consumo (LE) y Bluetooth.