Recolección de elementos no utilizados de ART de depuración

Organiza tus páginas con colecciones Guarda y categoriza el contenido según tus preferencias.

En esta página, se describe cómo depurar la corrección y los problemas de rendimiento de la recolección de elementos no utilizados (GC) de Android Runtime (ART). En él, se explica cómo usar las opciones de verificación de GC, identificar soluciones para las fallas de verificación de GC y medir y abordar los problemas de rendimiento de GC.

Para trabajar con ART, consulta las páginas de esta sección ART y Dalvik y el formato ejecutable de Dalvik. Si necesitas más ayuda para verificar el comportamiento de la app, consulta Cómo verificar el comportamiento de la app en el entorno de ejecución de Android (ART).

Descripción general de la GC de ART

ART tiene algunos planes de GC diferentes que consisten en ejecutar diferentes recopiladores de basura. A partir de Android 8 (Oreo), el plan predeterminado es la copia simultánea (CC). El otro plan de GC es la limpieza de marcas simultánea (CMS).

Estas son algunas de las características principales de la GC de copia simultánea:

• CC habilita el uso de un asignador de punteros de aumento llamado RegionTLAB. Esto asigna un búfer de asignación (TLAB) local de subproceso a cada subproceso de la app, que luego puede asignar objetos de su TLAB empujando el puntero "superior", sin ninguna sincronización.
• La CC realiza la desfragmentación del montón copiando objetos de forma simultánea sin pausar los subprocesos de la app. Esto se logra con la ayuda de una barrera de lectura que intercepta las lecturas de referencia del montón, sin necesidad de intervención del desarrollador de la app.
• La GC solo tiene una pequeña pausa, que es constante en el tiempo con respecto al tamaño del montón.
• CC se extiende para ser un GC generacional en Android 10 y versiones posteriores. Permite recopilar objetos jóvenes, que a menudo se vuelven inaccesibles con bastante rapidez, con poco esfuerzo. Esto ayuda a aumentar la capacidad de procesamiento de GC y retrasa considerablemente la necesidad de realizar una GC de montón completo.

El otro GC que aún admite ART es CMS. Esta GC también admite la compactación, pero no de forma simultánea. Se evita la compactación hasta que la app pasa a segundo plano, momento en el que se detienen los subprocesos de la app para realizar la compactación. La compactación también se vuelve necesaria cuando una asignación de objetos falla debido a la fragmentación. En este caso, es posible que la app no responda durante un tiempo.

Dado que el CMS rara vez se compacta y, por lo tanto, los objetos libres pueden no ser contiguos, usa un asignador basado en una lista libre llamado RosAlloc. Tiene un costo de asignación más alto en comparación con RegionTLAB. Por último, debido a la fragmentación interna, el uso de memoria para el montón de Java puede ser mayor para CMS que para CC.

Verificación de GC y opciones de rendimiento

Cambia el tipo de GC

Los OEMs pueden cambiar el tipo de GC. El proceso de cambio implica configurar la variable de entorno ART_USE_READ_BARRIER en el momento de la compilación. El valor predeterminado es verdadero, lo que habilita el recopilador de CC, ya que usa la barrera de lectura. Para el CMS, esta variable debe establecerse de forma explícita como falsa.

De forma predeterminada, el recopilador de CC se ejecuta en modo generacional en Android 10 y versiones posteriores. Para inhabilitar el modo generacional, se puede usar el argumento de línea de comandos -Xgc:nogenerational_cc. Como alternativa, la propiedad del sistema se puede establecer de la siguiente manera:

adb shell setprop dalvik.vm.gctype nogenerational_cc

Verifica el montón

La verificación del montón es probablemente la opción de GC más útil para depurar errores relacionados con la GC o daños en el montón. Si habilitas la verificación del montón, la GC verificará la exactitud del montón en algunos puntos durante el proceso de recolección de basura. La verificación del montón comparte las mismas opciones que las que cambian el tipo de GC. Si está habilitada, la verificación del montón verifica las raíces y se asegura de que los objetos accesibles solo hagan referencia a otros objetos accesibles. Para habilitar la verificación de GC, pasa los siguientes valores de -Xgc:

• Si está habilitada, [no]preverify realiza la verificación del montón antes de iniciar la GC.
• Si está habilitado, [no]presweepingverify realiza la verificación del montón antes de iniciar el proceso de barrido del recolector de elementos no utilizados.
• Si está habilitada, [no]postverify realiza la verificación del montón después de que el GC termina de barrer.
• [no]preverify_rosalloc, [no]postsweepingverify_rosalloc y [no]postverify_rosalloc son opciones de GC adicionales que solo verifican el estado de la contabilización interna de RosAlloc. Por lo tanto, solo se aplican con el recopilador de CMS, que usa el asignador de RosAlloc. Lo principal que se verifica es que los valores mágicos coincidan con las constantes esperadas y que los bloques de memoria libres estén registrados en el mapa free_page_runs_.

Rendimiento

Existen dos herramientas principales para medir el rendimiento de la GC: volcados de tiempo de GC y Systrace. También hay una versión avanzada de Systrace, llamada Perfetto. La forma visual de medir los problemas de rendimiento de la GC es usar Systrace y Perfetto para determinar qué GC están causando pausas largas o usurpando subprocesos de la app. Si bien la GC de ART mejoró significativamente con el tiempo, el comportamiento incorrecto del mutador, como la asignación excesiva, aún puede causar problemas de rendimiento.

Estrategia de recopilación

El GC de CC recopila datos ejecutando un GC joven o un GC de montón completo. Idealmente, el GC joven se ejecuta con más frecuencia. La GC realiza colecciones de CC jóvenes hasta que la capacidad de procesamiento (calculada en bytes liberados por segundo de duración de la GC) del ciclo de recopilación que acaba de terminar sea inferior a la capacidad de procesamiento promedio de las colecciones de CC de montón completo. Cuando esto ocurre, se elige el CC de montón completo para la siguiente GC simultánea en lugar del CC joven. Después de que se completa la recolección del montón completo, la siguiente GC vuelve a cambiar a la CC joven. Un factor clave que hace que esta estrategia funcione es que el CC joven no ajusta el límite de espacio en el montón después de que se completa. Esto hace que la CC joven ocurra con más frecuencia hasta que la capacidad de procesamiento sea menor que la CC de montón completo, lo que termina por aumentar el montón.

Usa SIGQUIT para obtener información del rendimiento de GC

Para obtener los tiempos de rendimiento de GC para las apps, envía SIGQUIT a las apps que ya se están ejecutando o pasa -XX:DumpGCPerformanceOnShutdown a dalvikvm cuando inicies un programa de línea de comandos. Cuando una app recibe el indicador de solicitud de ANR (SIGQUIT), volca información relacionada con sus bloqueos, pilas de subprocesos y el rendimiento de GC.

Para obtener volcados de tiempo de GC, usa lo siguiente:

adb shell kill -s QUIT PID

Esto crea un archivo (con la fecha y la hora en el nombre, como anr_2020-07-13-19-23-39-817) en /data/anr/. Este archivo contiene algunos volcados de ANR, así como los tiempos de GC. Para encontrar los tiempos de GC, busca Dumping cumulative Gc timings. Estos tiempos muestran algunos aspectos que pueden ser de interés, incluida la información del histograma para las fases y las pausas de cada tipo de GC. Por lo general, las pausas son más importantes para analizar. Por ejemplo:

young concurrent copying paused:	Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms

Esto muestra que la pausa promedio fue de 1.83 ms, lo que debería ser lo suficientemente bajo como para que no cause fotogramas perdidos en la mayoría de las apps y no debería ser motivo de preocupación.

Otra área de interés es el tiempo de suspensión, que mide cuánto tarda un subproceso en llegar a un punto de suspensión después de que el GC solicita que se suspenda. Este tiempo se incluye en las pausas de GC, por lo que es útil para determinar si las pausas largas se deben a que la GC es lenta o a que el subproceso se suspende lentamente. Este es un ejemplo de un tiempo normal para suspender en un Nexus 5:

suspend all histogram:	Sum: 1.513ms 99% C.I. 3us-546.560us Avg: 47.281us Max: 601us

Hay otras áreas de interés, como el tiempo total dedicado y la productividad de GC. Ejemplos:

Total time spent in GC: 502.251ms
Mean GC size throughput: 92MB/s
Mean GC object throughput: 1.54702e+06 objects/s

Este es un ejemplo de cómo volcar los tiempos de GC de una app que ya se está ejecutando:

adb shell kill -s QUIT PID
adb pull /data/anr/anr_2020-07-13-19-23-39-817

En este punto, los tiempos de GC están dentro de anr_2020-07-13-19-23-39-817. Este es un ejemplo de resultado de 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

Herramientas para analizar problemas de corrección de GC

Varios factores pueden causar fallas en ART. Los errores que se producen cuando se lee o se escribe en campos de objetos pueden indicar que el montón está dañado. Si la GC falla cuando se ejecuta, también podría indicar una corrupción del montón. La causa más común de la corrupción del montón es un código de app incorrecto. Afortunadamente, existen herramientas para depurar la GC y las fallas relacionadas con el montón, incluidas las opciones de verificación de montón especificadas arriba y CheckJNI.

CheckJNI

CheckJNI es un modo que agrega verificaciones de JNI para verificar el comportamiento de la app. Estas no están habilitadas de forma predeterminada por motivos de rendimiento. Las verificaciones detectan algunos errores que podrían dañar el montón, como el uso de referencias locales y globales no válidas o inactivas. Para habilitar CheckJNI, haz lo siguiente:

adb shell setprop dalvik.vm.checkjni true

El modo de copia forzada de CheckJNI es útil para detectar escrituras después del final de las regiones del array. Cuando se habilita, forcecopy hace que las funciones JNI de acceso al array muestren copias con zonas rojas. Una zona roja es una región al final o al principio del puntero que se muestra y que tiene un valor especial, que se verifica cuando se libera el array. Si los valores de la zona roja no coinciden con lo esperado, se produjo un desbordamiento o una falta de búfer. Esto hace que CheckJNI se cancele. Para habilitar el modo de copia forzada, haz lo siguiente:

adb shell setprop dalvik.vm.jniopts forcecopy

Un ejemplo de un error que CheckJNI debería detectar es escribir después del final de un array obtenido de GetPrimitiveArrayCritical. Esta operación puede dañar el montón de Java. Si la operación de escritura se encuentra dentro del área de la zona roja de CheckJNI, CheckJNI detecta el problema cuando se llama a ReleasePrimitiveArrayCritical correspondiente. De lo contrario, la operación de escritura daña algún objeto aleatorio en el montón de Java y puede provocar una falla de GC en el futuro. Si la memoria dañada es un campo de referencia, es posible que el GC detecte el error y muestre el error Se intentó marcar <ptr> que no está contenido por ningún espacio.

Este error ocurre cuando el GC intenta marcar un objeto para el que no puede encontrar un espacio. Después de que esta verificación falla, el GC recorre las raíces y trata de ver si el objeto no válido es una raíz. Desde aquí, hay dos opciones: El objeto es raíz o no.

Ejemplo de raíz no válida

En el caso de que el objeto sea una raíz no válida, imprime información útil: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

En este caso, vreg=1 dentro de com.google.gwt.collections.JavaReadableJsArray.get debería contener una referencia de montón, pero contiene un puntero no válido de la dirección 0x2. Esta raíz no es válida. Para depurar este problema, usa oatdump en el archivo oat y observa el método con la raíz no válida. En este caso, el error resultó ser un error del compilador en el backend de x86. Esta es la lista de cambios que corrigieron el problema: https://android-review.googlesource.com/#/c/133932/

Ejemplo de objeto dañado

Si el objeto no es raíz, se imprime un resultado similar al siguiente:

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

Cuando la corrupción del montón no es una raíz no válida, es difícil depurarla. Este mensaje de error indica que había al menos un objeto en el montón que apuntaba al objeto no válido.