Ler relatórios de bugs

Bugs são uma realidade em qualquer tipo de desenvolvimento – e relatórios de bugs são essenciais para identificar e resolver problemas. Todas as versões do Android suportam a captura de relatórios de bugs com o Android Debug Bridge (adb) ; As versões 4.2 e superiores do Android oferecem suporte a uma opção de desenvolvedor para receber relatórios de bugs e compartilhar via e-mail, Drive, etc.

Os relatórios de bugs do Android contêm dados dumpsys , dumpstate e logcat em formato de texto (.txt), permitindo que você pesquise facilmente conteúdo específico. As seções a seguir detalham os componentes do relatório de bugs, descrevem problemas comuns e fornecem dicas úteis e comandos grep para localizar logs 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 log logcat é um dump baseado em string de todas as informações logcat . A parte do sistema é reservada para o framework e tem um histórico mais longo que o main , que contém todo o resto. Cada linha normalmente começa com timestamp UID PID TID log-level , embora o UID possa não estar listado em versões mais antigas do Android.

Ver o log de eventos

Este log contém representações de strings de mensagens de log em formato binário. É menos barulhento que o log logcat , mas também um pouco mais difícil de ler. Ao visualizar logs de eventos, você pode pesquisar nesta seção o ID do processo (PID) 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 log incluem o seguinte:

  • V: detalhado
  • D: depuração
  • Eu: informação
  • W: aviso
  • E: erro

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

ANRs e impasses

Os relatórios de bugs podem ajudá-lo a identificar o que está causando erros de aplicativo que não responde (ANR) e eventos de conflito.

Identifique aplicativos que não respondem

Quando um aplicativo não responde dentro de um determinado período de tempo, geralmente devido a um thread principal bloqueado ou ocupado, o sistema encerra o processo e despeja a pilha em /data/anr . Para descobrir o culpado por trás de um ANR, use grep para am_anr no log de eventos binário.

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

Encontre rastreamentos de pilha

Muitas vezes você pode encontrar rastreamentos de pilha que correspondem a um ANR. Certifique-se de que o carimbo de data/hora e o PID nos rastreamentos da VM correspondam ao ANR que você está investigando e, em seguida, verifique o thread principal do processo. Tenha em mente:

  • O thread principal informa apenas o que o thread 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 ser inocente; alguma outra coisa pode ter ficado presa por um longo tempo - mas não o suficiente para ANR - antes de se soltar.)
  • Pode existir mais de um conjunto de rastreamentos de pilha ( VM TRACES JUST NOW e VM TRACES AT LAST ANR ). Certifique-se de estar visualizando a seção correta.

Encontre impasses

Os impasses geralmente aparecem primeiro como ANRs porque os threads estão travando. Se o impasse atingir o servidor do sistema, o watchdog acabará por matá-lo, levando a uma entrada no log semelhante a: WATCHDOG KILLING SYSTEM PROCESS . Da perspectiva do usuário, o dispositivo é reinicializado, embora tecnicamente seja uma reinicialização em tempo de execução, e não uma reinicialização verdadeira.

  • Em uma reinicialização em tempo de execução , o servidor do sistema morre e é reiniciado; o usuário vê o dispositivo retornar à animação de inicialização.
  • Em uma reinicialização , o kernel travou; o usuário vê o dispositivo retornar ao logotipo de inicialização do Google.

Para encontrar impasses, verifique as seções de rastreamentos da VM em busca de um padrão de thread A aguardando algo mantido pelo thread B, que por sua vez está aguardando algo mantido pelo thread A.

Atividades

Uma atividade é um componente do aplicativo que fornece uma tela com a qual os usuários interagem para fazer algo como discar um número, tirar uma foto, enviar um e-mail, etc. Do ponto de vista do relatório de bug, uma atividade é algo único e focado que um usuário pode fazer , o que torna muito importante localizar a atividade que estava em foco durante uma falha. As atividades (por meio do ActivityManager) executam processos, portanto, localizar todas as paradas e inícios de processos para uma determinada atividade também pode ajudar na solução de problemas.

Ver atividades focadas

Para visualizar um histórico de atividades focadas, pesquise am_focused_activity .

Ver início do processo

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

Determine se o dispositivo está se debatendo

Para determinar se o dispositivo está se debatendo , verifique se há um aumento anormal na atividade em torno de am_proc_died e am_proc_start em um curto período de tempo.

Memória

Como os dispositivos Android geralmente têm memória física restrita, o gerenciamento da memória de acesso aleatório (RAM) é 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.

Identifique pouca memória

Pouca memória pode causar problemas no sistema, pois mata alguns processos para liberar memória, mas continua iniciando outros processos. Para visualizar evidências corroborantes de pouca memória, verifique as concentrações das entradas am_proc_died e am_proc_start no log de eventos binário.

Pouca memória também pode retardar a alternância de tarefas e impedir tentativas de retorno (porque a tarefa para a qual o usuário estava tentando retornar foi encerrada). Se o inicializador foi encerrado, ele será reiniciado quando o usuário tocar no botão home e os registros mostrarão que o inicializador recarregou seu conteúdo.

Ver indicadores históricos

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

Ver indicadores de surra

Outros indicadores de sobrecarga do sistema (paginação, recuperação direta, etc.) incluem ciclos de consumo kswapd , kworker e mmcqd . (Tenha em mente que o relatório de bug coletado pode influenciar os indicadores de thrashing.)

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

Obtenha um instantâneo da memória

O instantâneo de memória é um dumpstate que lista processos Java e nativos em execução (para obter detalhes, consulte Visualizando alocações gerais de memória ). Tenha em mente que o instantâneo fornece apenas o estado em um momento específico; 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 receptores de transmissão assinam mensagens específicas (por meio de filtros), permitindo-lhes ouvir e responder 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.

Ver transmissões históricas

As 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 das últimas 50 transmissões em primeiro plano e das últimas 50 transmissões em segundo plano, bem como os receptores de cada transmissão. Receptores que possuem:

  • As entradas BroadcastFilter são registradas em tempo de execução e enviadas apenas para processos já em execução.
  • A entrada ResolveInfo é registrada por meio de entradas de manifesto. O ActivityManager inicia o processo para cada ResolveInfo se ainda não estiver em execução.

Ver transmissões ativas

As transmissões ativas são aquelas que ainda não foram enviadas. Um grande número na fila significa que o sistema não consegue despachar as transmissões com rapidez suficiente para acompanhar.

Ver ouvintes de transmissão

Para visualizar uma lista de receptores que estão ouvindo uma transmissão, verifique a Tabela do Resolvedor de Receptores na dumpsys activity broadcasts . O exemplo a seguir exibe todos os receptores ouvindo USER_PRESENT .

Monitore a contenção

O registro de contenção de monitor às vezes pode indicar uma contenção real de monitor, mas na maioria das vezes indica que o sistema está tão carregado que tudo ficou lento. Você poderá ver eventos de monitoramento longos registrados pelo ART no sistema ou no log de eventos.

No log 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 durante o download das atualizações da Google Play Store. Nesse caso, as mensagens do aplicativo Google Play Store ( finsky ) e installd aparecem antes das mensagens dex2oat .

A compilação também pode ocorrer em segundo plano quando um aplicativo está carregando um arquivo dex que ainda não foi compilado. Nesse caso, você não verá o log finsky ou installd .

Narrativa

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

Sincronizar cronogramas

Um relatório de bug reflete vários cronogramas paralelos: log do sistema, log de eventos, log do kernel e vários cronogramas especializados para transmissões, estatísticas de bateria, etc. Infelizmente, os cronogramas são frequentemente relatados usando diferentes bases de tempo.

Os carimbos de data/hora do sistema e do log de eventos estão no mesmo fuso horário do usuário (assim como a maioria dos outros carimbos de data/hora). Por exemplo, quando o usuário toca no botão home, o log 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 informa:

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

Os logs do kernel ( dmesg ) usam uma base de tempo diferente, marcando os itens de log com segundos desde a conclusão do bootloader. Para registrar esta escala de tempo em outras escalas de tempo, procure por mensagens de suspensão de saída e suspensão de 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 logs do kernel podem não incluir o tempo durante a suspensão, você deve registrar o log por partes entre as mensagens de entrada e saída de suspensão. Além disso, os logs do kernel usam o fuso horário UTC e devem ser ajustados ao fuso horário do usuário.

Identifique o horário do relatório de bug

Para determinar quando um relatório de bug foi obtido, primeiro verifique o log do sistema (Logcat) para o dumpstate: begin :

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

Em seguida, verifique os carimbos de data e hora do log do kernel ( dmesg ) para a mensagem Starting service 'bugreport' :

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

Trabalhe de trás para frente para correlacionar os dois eventos, tendo em mente as advertências mencionadas em Sincronização de cronogramas . Embora muita coisa aconteça depois que o relatório de bug é iniciado, a maior parte das atividades não é muito útil, pois o ato de obter o relatório de bug carrega o sistema substancialmente.

Poder

O log de eventos contém o status de energia da tela, onde 0 é tela desligada, 1 é tela ligada e 2 é proteção de teclado concluída.

Os relatórios de bugs também contêm estatísticas sobre wake locks, um mecanismo usado pelos desenvolvedores de aplicativos para indicar que seus aplicativos precisam manter o dispositivo ligado. (Para obter detalhes sobre wake locks, consulte PowerManager.WakeLock e Keep the CPU on .)

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 inclui 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 esses wake locks.

Para obter 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 usando arquivos de relatório de bugs do Android.

Pacotes

A seção DUMP OF SERVICE package contém versões do aplicativo (e outras informações úteis).

Processos

Os relatórios de bugs contêm uma grande quantidade de dados para processos, incluindo horário de início e término, duração do tempo de execução, serviços associados, pontuação oom_adj , etc. Para obter detalhes sobre como o Android gerencia processos, consulte Processos e Threads .

Determinar o tempo de execução do processo

A seção procstats contém estatísticas completas sobre há quanto tempo os processos e serviços associados estão em execução. Para um resumo rápido e legível, pesquise AGGREGATED OVER para visualizar os dados das últimas três ou 24 horas e, em seguida, pesquise Summary: para visualizar a lista de processos, por quanto tempo esses processos foram executados em várias prioridades e sua RAM uso formatado como min-average-max PSS/min-average-max USS.

Razões pelas quais 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 ao processo um valor oom_adj , que pode ser atualizado dinamicamente pelo ActivityManager). A saída é semelhante à de um instantâneo de memória , mas inclui informações adicionais 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 com prioridade vis (visível) porque o processo do sistema está vinculado ao seu NetworkLocationService .

Verificações

Use as etapas a seguir para identificar aplicativos que executam varreduras excessivas de Bluetooth Low Energy (BLE):

  • Encontre mensagens de log 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 log. Neste exemplo, "24840" e "24851" são PID (ID do processo) e TID (ID do thread).
  • Localize o aplicativo associado ao PID:
    PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}
    

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

  • Procure o nome do pacote no Google Play para identificar o aplicativo 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 verificações BLE e associa essas atividades ao aplicativo inicial. Para obter detalhes, consulte Verificações de baixa energia (LE) e Bluetooth .