Esta página descreve como depurar a coleta de lixo do Android Runtime (ART) (GC). Explica como usar a verificação de GC identificar soluções para falhas na verificação de GC e medir e resolver problemas de desempenho do GC.
Para trabalhar com o ART, consulte as páginas desta página ART e Dalvik e o formato Dalvik Executable. Se precisar de mais ajuda para verificar o comportamento do app, consulte Verificando comportamento do app no Android Runtime (ART).
Visão geral da GC da ART
O ART tem alguns planos de GC diferentes que consistem em executar diferentes coletores. A partir do Android 8 (Oreo), o plano padrão é a cópia simultânea (CC, na sigla em inglês). O outro plano de coleta de lixo é a limpeza simultânea de marca (CMS, na sigla em inglês).
Algumas das principais características da GC de cópia simultânea são:
- O CC permite o uso de um alocador de ponteiro de promoção chamado RegionTLAB. Isso aloca uma linha de execução local para cada linha de execução do app, que pode alocar objetos fora do TLAB batendo o "topo" sem qualquer sincronização.
- O CC realiza a desfragmentação de heap copiando objetos simultaneamente sem pausar as linhas de execução do aplicativo. Isso é conseguido com a ajuda de uma barreira de leitura que intercepta leituras de referência do heap, sem a necessidade de qualquer intervenção do desenvolvedor do aplicativo.
- A GC tem apenas uma pequena pausa, que é constante no tempo em relação ao tamanho da heap.
- A CC se estende para ser uma GC geracional no Android 10 e versões mais recentes. Ele permite coletar objetos jovens, que muitas vezes se tornam inacessíveis rapidamente, com pouco esforço. Isso ajuda aumentando a capacidade de processamento de GC e atrasando consideravelmente a necessidade de realizar uma GC de heap completa.
O outro GC que o ART ainda aceita é o CMS. Isso O GC também oferece suporte à compactação, mas não simultaneamente. A compactação deve ser evitada até que o app entra em segundo plano, momento em que as linhas de execução do app são pausadas para realizar a compactação. A compactação também se torna necessária quando uma alocação de objeto falha devido à fragmentação. Neste caso o app possa parar de responder por algum tempo.
Como o CMS raramente se compacta e, portanto, os objetos livres podem não ser contíguos, ele usa uma alocador baseado em lista livre chamado RosAlloc. Ele tem um custo de alocação maior em comparação ao RegionTLAB. Por fim, devido à fragmentação interna, o uso de memória para a heap Java pode ser maior no CMS do que na CC.
Verificação de GC e opções de performance
Mudar o tipo de GC
OEMs podem mudar o tipo de GC. O processo de mudança
envolve a configuração da variável de ambiente ART_USE_READ_BARRIER
no tempo de build.
O valor padrão é verdadeiro, o que ativa o coletor de CC porque usa a barreira de leitura. Para o CMS,
deve ser definida explicitamente como falsa.
Por padrão, o coletor CC é executado no modo geracional no Android 10 e versões mais recentes. Para
desativar o modo geracional, o argumento de linha de comando -Xgc:nogenerational_cc
poderá ser
usados. Como alternativa, a propriedade do sistema pode ser definida da seguinte maneira:
adb shell setprop dalvik.vm.gctype nogenerational_ccO coletor de CMS sempre é executado no modo geracional.
Verificar a heap
A verificação de heap é provavelmente a opção de GC mais útil para depuração
Erros relacionados a GC ou corrupção de heap. Ativar a verificação de heap faz com que a GC
para verificar a exatidão da heap em alguns pontos durante a
o processo de coleta de dados. A verificação de heap compartilha as mesmas opções que as
alterar o tipo de GC. Se ativada, a verificação de heap verifica as raízes e
garante que os objetos acessíveis façam referência apenas a outros objetos acessíveis. coleta de lixo (GC)
a verificação é ativada transmitindo os seguintes valores -Xgc
:
- Se ativado, o
[no]preverify
executa a verificação de heap antes de iniciar a GC. - Se ativado, o
[no]presweepingverify
executa a verificação de heap antes de iniciar o processo de varredura do coletor de lixo. - Se ativado, o
[no]postverify
executa a verificação de heap após a coleta de lixo conclui a varredura. [no]preverify_rosalloc
,[no]postsweepingverify_rosalloc
e[no]postverify_rosalloc
são opções adicionais de GC que verificam somente o estado da contabilidade interna da RosAlloc. Portanto, elas são aplicáveis apenas o coletor de CMS, que usa o alocador RosAlloc. Os principais itens verificados são que os valores mágicos correspondam às constantes esperadas e que os blocos livres de memória sejam registrados no mapafree_page_runs_
.
Desempenho
Há duas ferramentas principais para medir o desempenho do GC, o tempo dele dumps e Systrace. Há também uma versão avançada do Systrace, chamada Perfetto. A forma visual de medir problemas de desempenho do GC é usar o Systrace e o Perfetto para determinar quais GCs estão causando pausas longas ou a forçar linhas de execução do app. Embora a coleta de lixo da ART tenha melhorado significativamente ao longo do tempo, uma má estrutura como alocação excessiva, ainda podem causar problemas de desempenho
Estratégia de coleta
O GC do CC é coletado executando uma GC nova ou de todo o heap. Idealmente, o coletor de lixo (GC) jovem seja executada com mais frequência. O GC realiza coletas novas de CC até a capacidade (calculada por bytes) liberados/segundo de duração da GC) do ciclo de coleta recém-finalizado é menor que a capacidade média de coleções de CC de todo o heap. Quando isso ocorre, o CC com heap completo é escolhido para o próximo GC simultânea em vez de CC jovem. Depois que a coleta de heap completa for concluída, O GC é alterado de volta para o CC jovem. Um fator importante que faz essa estratégia funcionar é que o jovem CC não ajusta o limite de consumo de heap após a conclusão. Isso faz com que o CC jovem aconteça mais e com mais frequência até que a capacidade de processamento seja menor do que a de CC com heap completa, o que acaba aumentando o heap.
Usar SIGQUIT para obter informações de desempenho do GC
Para acessar os tempos de desempenho da coleta de lixo para apps, envie SIGQUIT
para
já estão em execução ou transmitir -XX:DumpGCPerformanceOnShutdown
como dalvikvm
ao iniciar um programa de linha de comando. Quando um app recebe
o indicador de solicitação de ANR (SIGQUIT
), ele despeja informações relacionadas aos bloqueios,
pilhas de linhas de execução e o desempenho do GC.
Para obter despejos de tempo de GC, use:
adb shell kill -s QUIT PID
Isso cria um arquivo (com a data e a hora no nome, por exemplo, anr_2020-07-13-19-23-39-817)
em /data/anr/
. Isso
contém alguns despejos de ANR e marcações de tempo de GC. Você pode localizar
Tempos de GC pesquisando por Tempos de Gc cumulativos. Esses tempos
mostrar alguns itens que podem ser interessantes, incluindo as informações do histograma de
as fases e pausas de cada tipo de GC. É mais importante analisar as pausas
Exemplo:
young concurrent copying paused: Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms
Isso mostra que a pausa média foi de 1,83 ms, o que deve ser baixo o suficiente para ela não causa perda de frames na maioria dos apps e não deve ser uma preocupação.
Outra área de interesse é a hora da suspensão, o que mede quanto tempo uma linha de execução leva para chegar a um ponto de suspensão após o GC solicitar que ela é suspensa. Esse tempo está incluído nas pausas de GC, por isso é útil determinar se pausas longas são causadas pela GC lenta ou pelo thread suspendendo lentamente. Este é um exemplo de tempo normal para a suspensão em um Nexus 5:
suspend all histogram: Sum: 1.513ms 99% C.I. 3us-546.560us Avg: 47.281us Max: 601us
Há outras áreas de interesse, incluindo o tempo total gasto e o GC e aumentar a capacidade de processamento. Exemplos:
Total time spent in GC: 502.251ms Mean GC size throughput: 92MB/s Mean GC object throughput: 1.54702e+06 objects/s
Confira um exemplo de como despejar os tempos de GC de um app que já está em execução:
adb shell kill -s QUIT PID
adb pull /data/anr/anr_2020-07-13-19-23-39-817
Nesse momento, os tempos da GC estão dentro de anr_2020-07-13-19-23-39-817
. Confira um exemplo de saída
do Google Maps:
Start Dumping histograms for 2195 iterations for concurrent copying MarkingPhase: Sum: 258.127s 99% C.I. 58.854ms-352.575ms Avg: 117.651ms Max: 641.940ms ScanCardsForSpace: Sum: 85.966s 99% C.I. 15.121ms-112.080ms Avg: 39.164ms Max: 662.555ms ScanImmuneSpaces: Sum: 79.066s 99% C.I. 7.614ms-57.658ms Avg: 18.014ms Max: 546.276ms ProcessMarkStack: Sum: 49.308s 99% C.I. 6.439ms-81.640ms Avg: 22.464ms Max: 638.448ms ClearFromSpace: Sum: 35.068s 99% C.I. 6.522ms-40.040ms Avg: 15.976ms Max: 633.665ms SweepSystemWeaks: Sum: 14.209s 99% C.I. 3.224ms-15.210ms Avg: 6.473ms Max: 201.738ms CaptureThreadRootsForMarking: Sum: 11.067s 99% C.I. 0.835ms-13.902ms Avg: 5.044ms Max: 25.565ms VisitConcurrentRoots: Sum: 8.588s 99% C.I. 1.260ms-8.547ms Avg: 1.956ms Max: 231.593ms ProcessReferences: Sum: 7.868s 99% C.I. 0.002ms-8.336ms Avg: 1.792ms Max: 17.376ms EnqueueFinalizerReferences: Sum: 3.976s 99% C.I. 0.691ms-8.005ms Avg: 1.811ms Max: 16.540ms GrayAllDirtyImmuneObjects: Sum: 3.721s 99% C.I. 0.622ms-6.702ms Avg: 1.695ms Max: 14.893ms SweepLargeObjects: Sum: 3.202s 99% C.I. 0.032ms-6.388ms Avg: 1.458ms Max: 549.851ms FlipOtherThreads: Sum: 2.265s 99% C.I. 0.487ms-3.702ms Avg: 1.031ms Max: 6.327ms VisitNonThreadRoots: Sum: 1.883s 99% C.I. 45us-3207.333us Avg: 429.210us Max: 27524us InitializePhase: Sum: 1.624s 99% C.I. 231.171us-2751.250us Avg: 740.220us Max: 6961us ForwardSoftReferences: Sum: 1.071s 99% C.I. 215.113us-2175.625us Avg: 488.362us Max: 7441us ReclaimPhase: Sum: 490.854ms 99% C.I. 32.029us-6373.807us Avg: 223.623us Max: 362851us EmptyRBMarkBitStack: Sum: 479.736ms 99% C.I. 11us-3202.500us Avg: 218.558us Max: 13652us CopyingPhase: Sum: 399.163ms 99% C.I. 24us-4602.500us Avg: 181.851us Max: 22865us ThreadListFlip: Sum: 295.609ms 99% C.I. 15us-2134.999us Avg: 134.673us Max: 13578us ResumeRunnableThreads: Sum: 238.329ms 99% C.I. 5us-2351.250us Avg: 108.578us Max: 10539us ResumeOtherThreads: Sum: 207.915ms 99% C.I. 1.072us-3602.499us Avg: 94.722us Max: 14179us RecordFree: Sum: 188.009ms 99% C.I. 64us-312.812us Avg: 85.653us Max: 2709us MarkZygoteLargeObjects: Sum: 133.301ms 99% C.I. 12us-734.999us Avg: 60.729us Max: 10169us MarkStackAsLive: Sum: 127.554ms 99% C.I. 13us-417.083us Avg: 58.111us Max: 1728us FlipThreadRoots: Sum: 126.119ms 99% C.I. 1.028us-3202.499us Avg: 57.457us Max: 11412us SweepAllocSpace: Sum: 117.761ms 99% C.I. 24us-400.624us Avg: 53.649us Max: 1541us SwapBitmaps: Sum: 56.301ms 99% C.I. 10us-125.312us Avg: 25.649us Max: 1475us (Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 33.047ms 99% C.I. 9us-49.931us Avg: 15.055us Max: 72us (Paused)SetFromSpace: Sum: 11.651ms 99% C.I. 2us-49.772us Avg: 5.307us Max: 71us (Paused)FlipCallback: Sum: 7.693ms 99% C.I. 2us-32us Avg: 3.504us Max: 32us (Paused)ClearCards: Sum: 6.371ms 99% C.I. 250ns-49753ns Avg: 207ns Max: 188000ns Sweep: Sum: 5.793ms 99% C.I. 1us-49.818us Avg: 2.639us Max: 93us UnBindBitmaps: Sum: 5.255ms 99% C.I. 1us-31us Avg: 2.394us Max: 31us Done Dumping histograms concurrent copying paused: Sum: 315.249ms 99% C.I. 49us-1378.125us Avg: 143.621us Max: 7722us concurrent copying freed-bytes: Avg: 34MB Max: 54MB Min: 2062KB Freed-bytes histogram: 0:4,5120:5,10240:19,15360:69,20480:167,25600:364,30720:529,35840:405,40960:284,46080:311,51200:38 concurrent copying total time: 569.947s mean time: 259.657ms concurrent copying freed: 1453160493 objects with total size 74GB concurrent copying throughput: 2.54964e+06/s / 134MB/s per cpu-time: 157655668/s / 150MB/s Average major GC reclaim bytes ratio 0.486928 over 2195 GC cycles Average major GC copied live bytes ratio 0.0894662 over 2199 major GCs Cumulative bytes moved 6586367960 Cumulative objects moved 127490240 Peak regions allocated 376 (94MB) / 2048 (512MB) Start Dumping histograms for 685 iterations for young concurrent copying ScanCardsForSpace: Sum: 26.288s 99% C.I. 8.617ms-77.759ms Avg: 38.377ms Max: 432.991ms ProcessMarkStack: Sum: 21.829s 99% C.I. 2.116ms-71.119ms Avg: 31.868ms Max: 98.679ms ClearFromSpace: Sum: 19.420s 99% C.I. 5.480ms-50.293ms Avg: 28.351ms Max: 507.330ms ScanImmuneSpaces: Sum: 9.968s 99% C.I. 8.155ms-30.639ms Avg: 14.552ms Max: 46.676ms SweepSystemWeaks: Sum: 6.741s 99% C.I. 3.655ms-14.715ms Avg: 9.841ms Max: 22.142ms GrayAllDirtyImmuneObjects: Sum: 4.466s 99% C.I. 0.584ms-14.315ms Avg: 6.519ms Max: 24.355ms FlipOtherThreads: Sum: 3.672s 99% C.I. 0.631ms-16.630ms Avg: 5.361ms Max: 18.513ms ProcessReferences: Sum: 2.806s 99% C.I. 0.001ms-9.459ms Avg: 2.048ms Max: 11.951ms EnqueueFinalizerReferences: Sum: 1.857s 99% C.I. 0.424ms-8.609ms Avg: 2.711ms Max: 24.063ms VisitConcurrentRoots: Sum: 1.094s 99% C.I. 1.306ms-5.357ms Avg: 1.598ms Max: 6.831ms SweepArray: Sum: 711.032ms 99% C.I. 0.022ms-3.502ms Avg: 1.038ms Max: 7.307ms InitializePhase: Sum: 667.346ms 99% C.I. 303us-2643.749us Avg: 974.227us Max: 3199us VisitNonThreadRoots: Sum: 388.145ms 99% C.I. 103.911us-1385.833us Avg: 566.635us Max: 5374us ThreadListFlip: Sum: 202.730ms 99% C.I. 18us-2414.999us Avg: 295.956us Max: 6780us EmptyRBMarkBitStack: Sum: 132.934ms 99% C.I. 8us-1757.499us Avg: 194.064us Max: 8495us ResumeRunnableThreads: Sum: 109.593ms 99% C.I. 6us-4719.999us Avg: 159.989us Max: 11106us ResumeOtherThreads: Sum: 86.733ms 99% C.I. 3us-4114.999us Avg: 126.617us Max: 19332us ForwardSoftReferences: Sum: 69.686ms 99% C.I. 14us-2014.999us Avg: 101.731us Max: 4723us RecordFree: Sum: 58.889ms 99% C.I. 0.500us-185.833us Avg: 42.984us Max: 769us FlipThreadRoots: Sum: 58.540ms 99% C.I. 1.034us-4314.999us Avg: 85.459us Max: 10224us CopyingPhase: Sum: 52.227ms 99% C.I. 26us-728.749us Avg: 76.243us Max: 2060us ReclaimPhase: Sum: 37.207ms 99% C.I. 7us-2322.499us Avg: 54.316us Max: 3826us (Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 23.859ms 99% C.I. 11us-98.917us Avg: 34.830us Max: 128us FreeList: Sum: 20.376ms 99% C.I. 2us-188.875us Avg: 29.573us Max: 998us MarkZygoteLargeObjects: Sum: 18.970ms 99% C.I. 4us-115.749us Avg: 27.693us Max: 122us (Paused)SetFromSpace: Sum: 12.331ms 99% C.I. 3us-94.226us Avg: 18.001us Max: 109us SwapBitmaps: Sum: 11.761ms 99% C.I. 5us-49.968us Avg: 17.169us Max: 67us ResetStack: Sum: 4.317ms 99% C.I. 1us-64.374us Avg: 6.302us Max: 190us UnBindBitmaps: Sum: 3.803ms 99% C.I. 4us-49.822us Avg: 5.551us Max: 70us (Paused)ClearCards: Sum: 3.336ms 99% C.I. 250ns-7000ns Avg: 347ns Max: 7000ns (Paused)FlipCallback: Sum: 3.082ms 99% C.I. 1us-30us Avg: 4.499us Max: 30us Done Dumping histograms young concurrent copying paused: Sum: 229.314ms 99% C.I. 37us-2287.499us Avg: 334.764us Max: 6850us young concurrent copying freed-bytes: Avg: 44MB Max: 50MB Min: 9132KB Freed-bytes histogram: 5120:1,15360:1,20480:6,25600:1,30720:1,35840:9,40960:235,46080:427,51200:4 young concurrent copying total time: 100.823s mean time: 147.187ms young concurrent copying freed: 519927309 objects with total size 30GB young concurrent copying throughput: 5.15683e+06/s / 304MB/s per cpu-time: 333152554/s / 317MB/s Average minor GC reclaim bytes ratio 0.52381 over 685 GC cycles Average minor GC copied live bytes ratio 0.0512109 over 685 minor GCs Cumulative bytes moved 1542000944 Cumulative objects moved 28393168 Peak regions allocated 376 (94MB) / 2048 (512MB) Total time spent in GC: 670.771s Mean GC size throughput: 159MB/s per cpu-time: 177MB/s Mean GC object throughput: 2.94152e+06 objects/s Total number of allocations 1974199562 Total bytes allocated 104GB Total bytes freed 104GB Free memory 10MB Free memory until GC 10MB Free memory until OOME 442MB Total memory 80MB Max memory 512MB Zygote space size 2780KB Total mutator paused time: 544.563ms Total time waiting for GC to complete: 117.494ms Total GC count: 2880 Total GC time: 670.771s Total blocking GC count: 1 Total blocking GC time: 86.373ms Histogram of GC count per 10000 ms: 0:259879,1:2828,2:24,3:1 Histogram of blocking GC count per 10000 ms: 0:262731,1:1 Native bytes total: 30599192 registered: 8947416 Total native bytes at last GC: 30344912
Ferramentas para analisar problemas de correção de GC
Várias coisas podem causar falhas no ART. Falhas que ocorrer leitura ou gravação em campos de objeto podem indicar corrupção de heap. Se o O GC trava quando está em execução e também pode apontar para corrupção da pilha. A causa mais comum de corrupção de heap é o código incorreto do app. Felizmente, existem ferramentas para depurar GC e falhas relacionadas à heap, incluindo as opções de verificação especificadas acima e CheckJNI.
CheckJNI
CheckJNI é um modo que adiciona verificações de JNI para conferir o comportamento do app. eles não são ativados pelo padrão por motivos de desempenho. As verificações capturam alguns erros que podem corromper a heap, como o uso de referências locais e globais inválidas/desatualizadas. Para ativar o CheckJNI:
adb shell setprop dalvik.vm.checkjni true
O modo forcecopy do CheckJNI é útil para detectar grava após o final das regiões da matriz. Quando ativado, "forcecopy" faz com que a matriz acessar funções JNI para retornar cópias com zonas vermelhas. Um vermelho zona é uma região no final/início do ponteiro retornado que tem um valor especial, que é verificado quando a matriz é liberada. Se os valores em a zona vermelha não corresponde ao esperado, um buffer excedido ou insuficiente. Isso faz com que CheckJNI seja cancelado. Para ativar modo forcecopy:
adb shell setprop dalvik.vm.jniopts forcecopy
Um exemplo de erro que o CheckJNI deve detectar é gravar após o fim do
uma matriz recebida de GetPrimitiveArrayCritical
. Essa operação
pode corromper a heap Java. Se a gravação for
dentro da área da zona vermelha do CheckJNI, o CheckJNI detectará o problema quando
o ReleasePrimitiveArrayCritical
correspondente é chamado. Caso contrário,
a gravação corrompe algum objeto aleatório
na heap Java e pode causar uma futura falha do GC. Se a memória corrompida
é um campo de referência, o GC pode capturar o erro e imprimir o erro Tried to
marcar <ptr> não incluídos em espaços.
Esse erro ocorre quando o GC tenta marcar um objeto que não pode encontrar um espaço. Quando a verificação falha, a GC passa pelas raízes e tenta verifique se o objeto inválido é uma raiz. A partir daqui, há duas opções: O objeto é uma raiz ou um objeto não raiz.
Exemplo de raiz inválido
No caso de o objeto ser uma raiz inválida, será gerado um
informações úteis:
art E 5955 5955 art/runtime/gc/collector/mark_sweep.cc:383] Tried to mark 0x2
not contained by any spaces
art E 5955 5955 art/runtime/gc/collector/mark_sweep.cc:384] Attempting see if it's a bad root art E 5955 5955 art/runtime/gc/collector/mark_sweep.cc:485] Found invalid root: 0x2 art E 5955 5955 art/runtime/gc/collector/mark_sweep.cc:486] Type=RootJavaFrame thread_id=1 location=Visiting method 'java.lang.Object com.google.gwt.collections.JavaReadableJsArray.get(int)' at dex PC 0x0002 (native PC 0xf19609d9) vreg=1
Neste caso, vreg=1
com.google.gwt.collections.JavaReadableJsArray.get
é
deve conter uma referência de heap, mas contém um ponteiro inválido
do endereço 0x2
. Essa é uma raiz inválida. Para
depure esse problema, use oatdump
no arquivo oat e procure
no método com a raiz inválida. Nesse caso, o erro ocorreu
ser um bug do compilador no back-end x86. Esta é a lista de mudanças que corrigiu o problema: https://android-review.googlesource.com/#/c/133932/
Exemplo de objeto corrompido
Se o objeto não for uma raiz, gere uma saída semelhante a esta impressões:
01-15 12:38:00.196 1217 1238 E art : Attempting see if it's a bad root 01-15 12:38:00.196 1217 1238 F art : art/runtime/gc/collector/mark_sweep.cc:381] Can't mark invalid object
Quando a corrupção da heap não é uma raiz inválida, é difícil depurar. Esta mensagem de erro indica que havia pelo menos um objeto na heap que apontava para o objeto inválido.