Esta página describe cómo depurar problemas de corrección y rendimiento de la recolección de basura (GC) de Android Runtime (ART). Explica cómo utilizar las opciones de verificación del GC, identificar soluciones para fallas de verificación del GC y medir y abordar los problemas de rendimiento del GC.
Para trabajar con ART, consulte las páginas de esta sección de ART y Dalvik , y el formato ejecutable de Dalvik . Para obtener ayuda adicional para verificar el comportamiento de la aplicación, consulte Verificar el comportamiento de la aplicación en el tiempo de ejecución de Android (ART) .
Descripción general de ART GC
ART tiene algunos planes de GC diferentes que consisten en ejecutar diferentes recolectores de basura. A partir de Android 8 (Oreo), el plan predeterminado es Copia simultánea (CC). El otro plan de GC es Concurrent Mark Sweep (CMS).
Algunas de las características principales de la Copia Concurrente GC son:
- CC permite el uso de un asignador de puntero de impacto llamado RegionTLAB. Esto asigna un búfer de asignación local de subprocesos (TLAB) a cada subproceso de la aplicación, que luego puede asignar objetos fuera de su TLAB tocando el puntero "superior", sin ninguna sincronización.
- CC realiza la desfragmentación del montón copiando objetos simultáneamente sin pausar los subprocesos de la aplicación. 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 alguna por parte del desarrollador de la aplicación.
- 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 superiores. Permite recoger objetos jóvenes, que a menudo se vuelven inalcanzables con bastante rapidez y con poco esfuerzo. Esto ayuda a aumentar el rendimiento del GC y a retrasar considerablemente la necesidad de realizar un GC completo.
El otro GC que ART todavía admite es CMS. Este GC también admite la compactación, pero no al mismo tiempo. Se evita la compactación hasta que la aplicación pasa a segundo plano, momento en el que los subprocesos de la aplicación se pausan para realizar la compactación. La compactación también se vuelve necesaria cuando la asignación de un objeto falla debido a la fragmentación. En este caso, es posible que la aplicación deje de responder durante algún tiempo.
Dado que CMS rara vez se compacta y, por lo tanto, los objetos libres pueden no ser contiguos, utiliza un asignador basado en listas libres llamado RosAlloc. Tiene un costo de asignación más alto en comparación con RegionTLAB. Finalmente, debido a la fragmentación interna, el uso de memoria para el montón de Java puede ser mayor para CMS que para CC.
Opciones de rendimiento y verificación del GC
Cambiar el tipo de GC
Los OEM 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 utiliza la barrera de lectura. Para CMS, esta variable debe establecerse explícitamente en falso.
De forma predeterminada, el recopilador de CC se ejecuta en modo generacional en Android 10 y versiones posteriores. Para deshabilitar el modo generacional, se puede utilizar el argumento de línea de comandos -Xgc:nogenerational_cc . Alternativamente, la propiedad del sistema se puede configurar de la siguiente manera:
adb shell setprop dalvik.vm.gctype nogenerational_ccEl recopilador de CMS siempre se ejecuta en modo generacional.
verificar el montón
La verificación del montón es probablemente la opción de GC más útil para depurar errores relacionados con el GC o corrupción del montón. Habilitar la verificación del montón hace que el GC verifique la corrección 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 garantiza que los objetos accesibles hagan referencia solo a otros objetos accesibles. La verificación de GC se habilita pasando los siguientes valores -Xgc :
- Si está habilitado,
[no]preverifyrealiza una verificación del montón antes de iniciar el GC. - Si está habilitado,
[no]presweepingverifyrealiza una verificación del montón antes de iniciar el proceso de barrido del recolector de basura. - Si está habilitado,
[no]postverifyrealiza la verificación del montón después de que el GC termina de barrer. -
[no]preverify_rosalloc,[no]postsweepingverify_rosallocy[no]postverify_rosallocson opciones de GC adicionales que verifican solo el estado de la contabilidad interna de RosAlloc. Por lo tanto, solo son aplicables con el recopilador CMS, que utiliza el asignador RosAlloc. Lo principal que se verifica es que los valores mágicos coincidan con las constantes esperadas y que todos los bloques de memoria libres estén registrados en el mapafree_page_runs_.
Actuación
Hay dos herramientas principales para medir el rendimiento de GC: los volcados de tiempo de GC y Systrace. También existe una versión avanzada de Systrace, llamada Perfetto. La forma visual de medir los problemas de rendimiento del GC es utilizar Systrace y Perfetto para determinar qué GC están provocando pausas prolongadas o apropiando subprocesos de aplicaciones. Aunque ART GC ha mejorado significativamente con el tiempo, el mal comportamiento del mutador, como una asignación excesiva, aún puede causar problemas de rendimiento.
Estrategia de cobranza
El CC GC recopila ejecutando un GC joven o un GC de montón completo. Lo ideal sería que el GC joven se ejecute con más frecuencia. El GC realiza recopilaciones de CC jóvenes hasta que el rendimiento (calculado en bytes liberados/segundo de duración del GC) del ciclo de recopilación recién finalizado es menor que el rendimiento medio de las recopilaciones de CC de montón completo. Cuando esto ocurre, se elige el CC de montón completo para el siguiente GC simultáneo en lugar del CC joven. Una vez completada la recopilación del montón completo, el siguiente GC vuelve a cambiar al CC joven. Un factor clave que hace que esta estrategia funcione es que el CC joven no ajusta el límite de huella del montón una vez que se completa. Esto hace que el CC joven ocurra cada vez con más frecuencia hasta que el rendimiento es menor que el CC del montón completo, lo que termina haciendo crecer el montón.
Utilice SIGQUIT para obtener información sobre el rendimiento del GC
Para obtener tiempos de rendimiento de GC para aplicaciones, envíe SIGQUIT a las aplicaciones que ya se están ejecutando o pase -XX:DumpGCPerformanceOnShutdown a dalvikvm al iniciar un programa de línea de comandos. Cuando una aplicación recibe la señal de solicitud ANR ( SIGQUIT ), descarga información relacionada con sus bloqueos, pilas de subprocesos y rendimiento de GC.
Para obtener volcados de tiempo de GC, use:
adb shell kill -s QUIT PID
Esto crea un archivo (con la fecha y 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 tiempos de GC. Puede localizar los tiempos de GC buscando Dumping cumulative Gc timings . Estos tiempos muestran algunas cosas que pueden ser de interés, incluida la información del histograma para las fases y pausas de cada tipo de GC. Las pausas suelen ser más importantes de observar. 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 no causar fotogramas perdidos en la mayoría de las aplicaciones y no debería ser una preocupación.
Otra área de interés es el tiempo de suspensión, que mide cuánto tiempo le toma a un hilo alcanzar un punto de suspensión después de que el GC solicita que se suspenda. Este tiempo se incluye en las pausas del GC, por lo que es útil para determinar si las pausas largas se deben a que el GC es lento o el subproceso se suspende lentamente. A continuación se muestra un ejemplo de un tiempo normal de suspensión 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, incluido el tiempo total invertido y el rendimiento del GC. Ejemplos:
Total time spent in GC: 502.251ms Mean GC size throughput: 92MB/s Mean GC object throughput: 1.54702e+06 objects/s
A continuación se muestra un ejemplo de cómo volcar los tiempos de GC de una aplicación que ya se está ejecutando:
adb shell kill -s QUIT PIDadb 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 . A continuación se muestra un ejemplo de salida 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.
Varias cosas pueden provocar fallos dentro de ART. Los fallos que se producen al leer o escribir en campos de objetos pueden indicar corrupción del montón. Si el GC falla cuando se está ejecutando, también podría indicar que hay corrupción en el montón. La causa más común de corrupción del montón es el código de aplicación incorrecto. Afortunadamente, existen herramientas para depurar fallas relacionadas con GC y el montón, incluidas las opciones de verificación del montón especificadas anteriormente y CheckJNI.
VerificarJNI
CheckJNI es un modo que agrega comprobaciones JNI para verificar el comportamiento de la aplicación; estos no están habilitados de forma predeterminada por motivos de rendimiento. Las comprobaciones detectan algunos errores que podrían provocar daños en el montón, como el uso de referencias locales y globales no válidas o obsoletas. Para habilitar CheckJNI:
adb shell setprop dalvik.vm.checkjni true
El modo forcecopy de CheckJNI es útil para detectar escrituras más allá del final de las regiones de la matriz. Cuando está habilitado, forcecopy hace que las funciones JNI de acceso a la matriz devuelvan copias con zonas rojas. Una zona roja es una región al final/inicio del puntero devuelto que tiene un valor especial, que se verifica cuando se libera la matriz. Si los valores en la zona roja no coinciden con lo esperado, se produjo un desbordamiento o un desbordamiento del búfer. Esto hace que CheckJNI cancele. Para habilitar el modo de copia forzada:
adb shell setprop dalvik.vm.jniopts forcecopy
Un ejemplo de un error que CheckJNI debería detectar es escribir más allá del final de una matriz obtenida de GetPrimitiveArrayCritical . Esta operación puede dañar el montón de Java. Si la escritura está dentro del área de la zona roja de CheckJNI, CheckJNI detecta el problema cuando se llama al ReleasePrimitiveArrayCritical correspondiente. De lo contrario, la escritura corrompe algún objeto aleatorio en el montón de Java y puede provocar una futura falla del GC. Si la memoria dañada es un campo de referencia, entonces el GC puede detectar el error e imprimirlo. Se intentó marcar <ptr> sin espacios .
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 atraviesa las raíces e intenta ver si el objeto no válido es una raíz. A partir de aquí, hay dos opciones: el objeto es un objeto raíz o no raíz.
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, se supone vreg=1 dentro de com.google.gwt.collections.JavaReadableJsArray.get contiene una referencia de montón, pero contiene un puntero de dirección no válido 0x2 . Ésta es una raíz no válida. Para depurar este problema, use oatdump en el archivo oat y observe el método con la raíz no válida. En este caso, el error resultó ser un error del compilador en el backend x86. Aquí está la lista de cambios que lo solucionó: https://android-review.googlesource.com/#/c/133932/
Ejemplo de objeto corrupto
Si el objeto no es una 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 depurar. Este mensaje de error indica que había al menos un objeto en el montón que apuntaba al objeto no válido.