Como ler relatórios de bugs

Bugs são uma realidade em qualquer tipo de desenvolvimento, e os relatórios de bugs são essenciais para identificar e resolver problemas. Todas as versões do Android são compatíveis com a captura de relatórios de bugs com o Android Debug Bridge (adb). As versões 4.2 e mais recentes do Android são compatíveis com uma Opção do desenvolvedor para receber relatórios de bugs e compartilhar por e-mail, Google Drive etc.

Os relatórios de bugs do Android contêm dados de dumpsys, dumpstate e logcat no formato de texto (.txt), o que facilita a pesquisa de conteúdo específico. As seções a seguir detalham os componentes dr relatórios de bug, descrevem problemas comuns e fornecem dicas úteis e comandos do grep para localizar registros associados a esses bugs. A maioria das seções também inclui exemplos de comando e saída grep e/ou saída dumpsys.

Logcat

O registro logcat é um despejo baseado em string de todas as informações do logcat. A parte system é reservada para o framework e tem um histórico mais longo que o main, que contém todo o restante. Normalmente, cada linha começa com timestamp UID PID TID log-level, mas o UID pode não estar listado em versões mais antigas do Android.

Visualização do log de eventos

Este registro contém representações de strings de mensagens de registro em formato binário. Ele é menos ruidoso que o registro logcat, mas também é um pouco mais difícil de ler. Ao visualizar logs de eventos, você pode pesquisar nessa seção o código de processo (PID, na sigla em inglês) específico para ver o que um processo está fazendo. O formato básico é timestamp PID TID log-level log-tag tag-values

Os níveis de registro incluem o seguinte:

  • V: verbose (detalhado)
  • D: debug (depuração)
  • I: information (informação)
  • W: warning (aviso)
  • E: error (erro)

 

Para ver outras tags de log de eventos úteis, consulte /services/core/java/com/android/server/EventLogTags.logtags.

ANRs e deadlocks

Os relatórios de bug podem ajudar você a identificar o que está causando erros O app não está respondendo (ANR, na sigla em inglês) e eventos de deadlock.

Como identificar apps que não respondem

Quando um app não responde dentro de um certo tempo, geralmente devido a uma linha de execução principal bloqueada ou ocupada, o sistema elimina o processo e envia a pilha para /data/anr. Para descobrir o fator causador de um ANR, use um grep para am_anr no log de eventos binário.

Você também pode usar um grep para ANR in no registro logcat, que contém mais informações sobre o que estava usando a CPU no momento do ANR.

Como encontrar stack traces

Geralmente, você pode encontrar stack traces que correspondem a um ANR. Verifique se o carimbo de data/hora e o PID nos traces da VM correspondem ao ANR que você está investigando e, em seguida, verifique a linha de execução principal do processo. Informações importantes:

  • A linha de execução principal informa apenas o que a linha de execução estava fazendo no momento do ANR, o que pode ou não corresponder à verdadeira causa do ANR. A pilha no relatório de bug pode não ser a causa. Alguma outra coisa pode ter ficado travada por um longo período, mas não o suficiente para causar o ANR, antes de ser liberada.
  • É possível que haja mais de um conjunto de stack tracea (VM TRACES JUST NOW e VM TRACES AT LAST ANR). Verifique se você está visualizando a seção correta.

Como encontrar impasses

Em geral, os impasses aparecem primeiro como ANRs porque as linhas de execução estão ficando travadas. Se o impasse atingir o servidor do sistema, o watchdog acabará eliminando-o, levando a uma entrada no registro semelhante a: WATCHDOG KILLING SYSTEM PROCESS. Da perspectiva do usuário, o dispositivo será reinicializado, embora isso seja, tecnicamente, uma reinicialização de tempo de execução em vez de uma reinicialização real.

  • Em uma reinicialização de tempo de execução, o servidor do sistema é desativado e reiniciado. O usuário vê quando o dispositivo retorna à animação de inicialização.
  • Em uma reinicialização, o kernel falha. O usuário vê quando o dispositivo retorna ao logotipo de inicialização do Google.

Para encontrar deadlocks, verifique as seções de rastreio de VMs para um padrão de thread A aguardando algo retido pela thread B, que, por sua vez, está aguardando algo retido pela thread A.

Atividades

Uma Atividade é um componente de aplicativo que fornece uma tela que permite a interação com usuários para fazer algo, como discar um número, tirar uma foto, enviar um e-mail etc. De uma perspectiva do relatório do bug, uma atividade é uma coisa única, em foco e que pode ser realizada por um usuário, o que torna a localização da atividade que estava em foco durante uma falha muito importante. As atividades (via ActivityManager) executam processos, portanto, a localização de todas as paradas e inícios de processos para uma determinada atividade também pode ajudar na solução de problemas.

Como visualizar atividades em foco

Para ver um histórico de atividades em foco, pesquise por am_focused_activity.

Visualização de inícios de processo

Para ver um histórico de inícios de processos, pesquise por Start proc.

O dispositivo está com sobrecarga?

Para determinar se o dispositivo está com sobrecarga (link em inglês), verifique se há um aumento anormal na atividade em torno de am_proc_died e am_proc_start em um curto período.

Memória

Como os dispositivos Android geralmente têm memória física restrita, o gerenciamento da memória de acesso aleatório (RAM, na sigla em inglês) é fundamental. Os relatórios de bugs contêm vários indicadores de pouca memória, bem como um dumpstate que fornece um instantâneo da memória.

Como identificar pouca memória

A memória insuficiente pode fazer com que o sistema se sobrecarregue, já que ele elimina alguns processos para liberar memória, mas continua iniciando outros. Para ver evidência que corrobore que há pouca memória, verifique se há concentrações de entradas am_proc_died e am_proc_start no log de eventos binário.

A memória insuficiente também pode retardar a troca de tarefas e impedir tentativas de retorno (porque a tarefa para a qual o usuário estava tentando retornar foi eliminada). Se a tela de início for eliminada, ela será reiniciada quando o usuário tocar no botão home, e os registros mostrarão que a tela de início atualizou o conteúdo.

Como visualizar de indicadores históricos

A entrada am_low_memory no log de eventos binário indica que o último processo em cache foi eliminado. Depois disso, o sistema começa a eliminar serviços.

Como visualizar indicadores de sobrecarga

Outros indicadores de sobrecarga do sistema (paginação, recuperação direta etc.) incluem os ciclos de consumo kswapd, kworker e mmcqd. Lembre-se de que o relatório de bug que está sendo coletado pode influenciar os indicadores de sobrecarga.

Os registros de ANR podem fornecer um instantâneo semelhante da memória.

Como receber um instantâneo da memória

O instantâneo da memória é um dumpstate que lista os processos Java e nativos em execução (para ver detalhes, consulte Ver as alocações de memória gerais). Tenha em mente que o instantâneo mostra o estado apenas em um momento específico no tempo, então sistema pode estar em melhor (ou pior) estado antes do instantâneo.

Transmissões

Os aplicativos geram transmissões para enviar eventos dentro do aplicativo atual ou para outro aplicativo. Os broadcast receivers se inscrevem em mensagens específicas (por meio de filtros), permitindo que eles ouçam e respondam a uma transmissão. Os relatórios de bugs contêm informações sobre transmissões enviadas e não enviadas, bem como um dumpsys de todos os receptores que estão ouvindo uma transmissão específica.

Visualização de transmissões históricas

Transmissões históricas são aquelas que já foram enviadas, listadas em ordem cronológica inversa.

A seção de resumo é uma visão geral das últimas 300 transmissões em primeiro plano e das últimas 300 transmissões em segundo plano.

A seção de detalhes contém informações completas sobre as últimas 50 transmissões em primeiro plano e as últimas 50 transmissões em segundo plano, assim como os receptores de cada transmissão. Receptores com uma:

  • entrada BroadcastFilter são registrados no momento da execução e enviados apenas para processos já em execução;
  • entrada ResolveInfo são registrados pelas entradas de manifesto. O ActivityManager inicia o processo para cada ResolveInfo, se ainda não está em execução.

Visualização de transmissões ativas

Transmissões ativas são aquelas que ainda precisam ser enviadas. Um grande número na fila significa que o sistema não pode enviar as transmissões com rapidez suficiente para acompanhá-las.

Como visualizar listeners de transmissão

Para ver uma lista de receptores que estão ouvindo uma transmissão, consulte a Tabela de Resolvedor do Receptor em dumpsys activity broadcasts. O exemplo a seguir exibe todos os receptores que estão ouvindo o USER_PRESENT.

Contenção do monitoramento

A geração de registros de contenção do monitoramento às vezes pode indicar uma contenção real do monitoramento, mas, na maioria das vezes, indica que o sistema está tão carregado que há uma lentidão generalizada. Você pode ver eventos longos de monitoramento registrados por ART no sistema ou no log de eventos.

No registro do 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

No log de eventos:

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]

Compilação em segundo plano

A compilação pode ser cara e carregar o dispositivo.

A compilação pode ocorrer em segundo plano quando as atualizações da Google Play Store são transferidas por download. Nesse caso, as mensagens do app da Google Play Store (finsky) e installd aparecem antes de mensagens dex2oat.

A compilação também pode ocorrer em segundo plano quando um app está carregando um arquivo dex que ainda não foi compilado. Nesse caso, não haverá geração de registros finsky ou installd.

Narrativa

Estabelecer a narrativa de um problema (como ele começou, o que aconteceu, como o sistema reagiu) requer uma linha de tempo de eventos sólida. Você pode usar as informações do relatório do bug para sincronizar linhas do tempo em vários registros e determinar o carimbo de data/hora exato do relatório do bug.

Sincronização de linhas do tempo

Um relatório de bug reflete várias linhas de tempo paralelas: registro do sistema, log de eventos, registro de kernel e várias linhas do tempo especializadas para transmissões, estatísticas de bateria etc. Infelizmente, as linhas do tempo são frequentemente relatadas com diferentes bases de horário.

Os carimbos de data/hora do log de eventos e do sistema estão no mesmo fuso horário que o usuário (assim como a maioria dos outros carimbos de data/hora). Por exemplo, quando o usuário toca no botão home, o registro do sistema informa:

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 a mesma ação, o log de eventos relata:

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

Os registros de kernel (dmesg) usam uma base de horário diferente, que marca itens de registro com segundos desde que o carregador de inicialização seja concluído. Para registrar essa escala de tempo em outras escalas de tempo, procure as mensagens suspender saída e suspender entrada:

<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

Como os registros de kernel podem não incluir o tempo em suspensão, você precisa registrar o log entre as mensagens suspend entry e suspend exit. Além disso, os registros de kernel usam o fuso horário UTC e precisam ser ajustados ao fuso do usuário.

Como identificar o horário do relatório do bug

Para determinar quando um relatório de bug foi criado, primeiro procure dumpstate: begin no registro do sistema (Logcat):

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

Em seguida, procure a mensagem Starting service 'bugreport' nos carimbos de data/hora do registro de kernel (dmesg):

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

Trabalhe de trás para frente para correlacionar os dois eventos, tendo em mente as ressalvas mencionadas em Como sincronizar linhas do tempo. Embora haja muita coisa acontecendo depois que o relatório de bug é iniciado, a maioria das atividades não é muito útil, já que o ato de gerar o relatório do bug carrega o sistema substancialmente.

Energia

O log de eventos contém o status de energia da tela, em que 0 é a tela desligada, 1 é a tela ligada e 2 refere-se ao bloqueio do teclado.

Os relatórios de bugs também contêm estatísticas sobre wake locks, um mecanismo usado por desenvolvedores de apps para indicar que o aplicativo precisa que o dispositivo fique ligado. Para ver detalhes sobre wake locks, consulte PowerManager.WakeLock e Manter a CPU ligada.

As estatísticas agregadas de duração do wake lock rastreiam apenas o tempo em que um wake lock é realmente responsável por manter o dispositivo ativo, e não incluem o tempo com a tela ligada. Além disso, se vários wake locks forem mantidos simultaneamente, o tempo de duração do wake lock será distribuído entre eles.

Para receber mais ajuda na visualização do status de energia, use o Battery Historian, uma ferramenta de código aberto do Google para analisar o consumo de bateria com arquivos de relatórios de bug do Android.

Pacotes

A seção DUMP OF SERVICE package contém versões de aplicativos e outras informações úteis.

Processos

Os relatórios de bugs contêm uma quantidade enorme de dados de processos, incluindo tempo de início e parada, duração do tempo de execução, serviços associados, pontuação oom_adj etc. Para ver detalhes sobre como o Android gerencia os processos, consulte Processos e linhas de execução.

Como determinar o tempo de execução do processo

A seção procstats contém estatísticas completas sobre a duração da execução dos processos e serviços associados. Para ver um resumo rápido e legível, procure por AGGREGATED OVER para ver dados das últimas 3 ou 24 horas e, em seguida, procure por Summary: para ver a lista de processos, a duração da execução desses processos em várias prioridades e o respectivo uso de RAM formatado como min-average-max PSS/min-average-max USS.

Por que um processo está em execução?

A seção dumpsys activity processes lista todos os processos atualmente em execução, ordenados pela pontuação oom_adj (o Android indica a importância do processo atribuindo a ele um valor oom_adj, que pode ser atualizado dinamicamente pelo ActivityManagef). A saída é semelhante à de um instantâneo da memória, mas inclui outras informações sobre o que está causando a execução do processo. No exemplo abaixo, as entradas em negrito indicam que o processo gms.persistent está sendo executado na prioridade vis (visível) porque o processo do sistema está vinculado ao NetworkLocationService.

Verificações

Use as etapas a seguir para identificar apps que executam buscas excessivas por Bluetooth de baixa energia (BLE, na sigla em inglês):

  • Encontre mensagens de registro para BluetoothLeScanner: 
    $ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
  • Localize o PID nas mensagens de registro. Neste exemplo, "24840" e "24851" são o PID (código do processo) e o TID (código da thread).
  • Localize o app associado ao PID: 
    PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}

    Nesse exemplo, o nome do pacote é com.badapp.

  • Procure o nome do pacote no Google Play para identificar o app responsável: https://play.google.com/store/apps/details?id=com.badapp..

Observação: para dispositivos que executam o Android 7.0, o sistema coleta dados para buscas por BLE e associa essas atividades ao aplicativo que está iniciando. Para ver detalhes, consulte Buscas por Bluetooth de baixa energia (LE).