Questa pagina descrive come eseguire il debug di problemi di correttezza e prestazioni della raccolta dei rifiuti (GC) di Android Runtime (ART). Spiega come utilizzare le opzioni di verifica della scheda di gioco, identificare soluzioni per i problemi di verifica della scheda di gioco e misurare e risolvere i problemi di prestazioni della scheda di gioco.
Per utilizzare ART, consulta le pagine di questa sezione ART e Dalvik e il formato eseguibile Dalvik. Per ulteriore assistenza sulla verifica del comportamento delle app, consulta Verificare il comportamento delle app nel runtime Android (ART).
Panoramica di ART GC
ART ha diversi piani di GC che consistono nell'esecuzione di diversi garbage collector. A partire da Android 8 (Oreo), il piano predefinito è la copia simultanea (CC). L'altro piano di GC è Concurrent Mark Sweep (CMS).
Ecco alcune delle caratteristiche principali del GC con copia concorrente:
- CC consente l'utilizzo di un allocatore di puntatori con incremento chiamato RegionTLAB. In questo modo viene allocato un buffer di allocazione (TLAB) per thread a ogni thread dell'app, che può quindi allocare oggetti dal proprio TLAB spingendo il puntatore "top", senza alcuna sincronizzazione.
- CC esegue la deframmentazione dell'heap copiando contemporaneamente gli oggetti senza mettere in pausa i thread dell'app. Questo viene ottenuto con l'aiuto di una barriera di lettura che intercetta le letture dei riferimenti dall'heap, senza bisogno di alcun intervento da parte dello sviluppatore dell'app.
- Il GC ha solo una piccola interruzione, costante nel tempo rispetto alle dimensioni dell'heap.
- CC si estende a una GC generazionale in Android 10 e versioni successive. Consente di raccogliere oggetti recenti, che spesso diventano irraggiungibili abbastanza rapidamente, con poco sforzo. Ciò è utile perché aumenta la velocità effettiva della GC e ritarda notevolmente la necessità di eseguire una GC completa dell'heap.
L'altro gruppo di controllo che ART supporta ancora è CMS. Questo GC supporta anche la compattazione, ma non in modo concorrente. La compattazione viene evitata fino a quando l'app non viene messa in background, momento in cui i thread dell'app vengono messi in pausa per eseguire la compattazione. La compattazione diventa necessaria anche quando l'allocazione di un oggetto non va a buon fine a causa della frammentazione. In questo caso, l'app potrebbe non rispondere per un po' di tempo.
Poiché il CMS si compatta raramente e gli oggetti liberi potrebbero non essere contigui, utilizza un allocatore basato su una lista libera chiamato RosAlloc. Ha un costo di allocazione più elevato rispetto a RegionTLAB. Infine, a causa della frammentazione interna, l'utilizzo della memoria per l'heap Java può essere superiore per il CMS rispetto al CC.
Opzioni di verifica e prestazioni del GC
Modificare il tipo di gruppo di controllo
Gli OEM possono modificare il tipo di gruppo di caricamento. Il processo di modifica
prevede l'impostazione della variabile di ambiente ART_USE_READ_BARRIER
al momento della compilazione.
Il valore predefinito è true, il che attiva il raccoglitore CC in quanto utilizza la barriera di lettura. Per il CMS, questa variabile deve essere impostata esplicitamente su false.
Per impostazione predefinita, il raccoglitore CC viene eseguito in modalità generazionale in Android 10 e versioni successive. Per
disattivare la modalità generazionale, puoi
utilizzare l'argomento della riga di comando -Xgc:nogenerational_cc
. In alternativa, la proprietà di sistema può essere impostata come segue:
adb shell setprop dalvik.vm.gctype nogenerational_cc
Verifica l'heap
La verifica dell'heap è probabilmente l'opzione di GC più utile per il debug di errori correlati alla GC o alla corruzione dell'heap. L'attivazione della verifica dell'heap fa sì che il GC verifichi la correttezza dell'heap in alcuni punti durante il processo di raccolta del garbage. La verifica dell'heap condivide le stesse opzioni di quelle che cambiano il tipo di GC. Se abilitata, la verifica dell'heap verifica le radici e garantisce che gli oggetti raggiungibili facciano riferimento solo ad altri oggetti raggiungibili. La verifica GC viene attivata passando i seguenti valori -Xgc
:
- Se abilitato,
[no]preverify
esegue la verifica dell'heap prima di avviare la GC. - Se abilitata,
[no]presweepingverify
esegue la verifica dell'heap prima di avviare il processo di scansione del garbage collector. - Se abilitata,
[no]postverify
esegue la verifica dell'heap al termine della scansione del GC. [no]preverify_rosalloc
,[no]postsweepingverify_rosalloc
e[no]postverify_rosalloc
sono opzioni GC aggiuntive che verificano solo lo stato della contabilità interna di RosAlloc. Pertanto, sono applicabili solo con il collector CMS, che utilizza l'allocatore RosAlloc. I punti principali verificati sono che i valori magici corrispondano alle costanti previste e che i blocchi di memoria liberi siano tutti registrati nella mappafree_page_runs_
.
Prestazioni
Esistono due strumenti principali per misurare le prestazioni del GC: i dump dei tempi del GC e Systrace. Esiste anche una versione avanzata di Systrace, chiamata Perfetto. Il modo visivo per misurare i problemi di prestazioni del GC consiste nell'utilizzare Systrace e Perfetto per determinare quali GC stanno causando lunghe interruzioni o preemption dei thread dell'app. Sebbene la gestione del ciclo di vita dei componenti ART sia migliorata notevolmente nel tempo, un comportamento scorretto del mutatore, come un'allocazione eccessiva, può comunque causare problemi di prestazioni
Strategia di raccolta
Il GC CC esegue la raccolta di un GC giovane o di un GC full-heap. Idealmente, il nuovo GC viene eseguito più spesso. Il GC esegue raccolte CC giovani finché il throughput (calcolato in byte freed/secondo di durata del GC) del ciclo di raccolta appena terminato è inferiore al throughput medio delle raccolte CC con heap completo. In questo caso, per il successivo GC concorrenziale viene scelto il CC con heap completo anziché il CC giovane. Al termine della raccolta dell'heap completo, la raccolta del garbage successiva torna al CC giovane. Un fattore chiave che rende efficace questa strategia è che il CC giovane non regola il limite dell'impronta dell'heap al termine. Ciò fa sì che i CC giovani si verifichino sempre più spesso finché il throughput non è inferiore a quello dei CC con heap completo, con conseguente crescita dell'heap.
Utilizzare SIGQUIT per ottenere informazioni sul rendimento di Google Cloud
Per ottenere i tempi di esecuzione del GC per le app, invia SIGQUIT
alle app già in esecuzione o passa -XX:DumpGCPerformanceOnShutdown
a dalvikvm
quando avvii un programma a riga di comando. Quando un'app riceve il segnale di richiesta ANR (SIGQUIT
), esegue il dump delle informazioni relative ai blocchi, agli stack dei thread e alle prestazioni del GC.
Per ottenere dump dei tempi di GC, utilizza:
adb shell kill -s QUIT PID
Viene creato un file (con la data e l'ora nel nome, ad esempio anr_2020-07-13-19-23-39-817)
in /data/anr/
. Questo
file contiene alcuni dump ANR e i tempi di GC. Puoi trovare i tempi di GC cercando Dumping dei tempi di GC cumulativi. Questi tempi
mostrano alcuni aspetti che potrebbero essere di interesse, tra cui le informazioni sull'istogramma per
le fasi e le interruzioni di ogni tipo di GC. In genere, le interruzioni sono più importanti da esaminare. Ad esempio:
young concurrent copying paused: Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms
Ciò indica che la pausa media è stata di 1,83 ms, un valore sufficientemente basso da non causare frame mancanti nella maggior parte delle app e non dovrebbe essere motivo di preoccupazione.
Un'altra area di interesse è il tempo di sospensione, che misura il tempo necessario a un thread per raggiungere un punto di sospensione dopo che il GC ne ha richiesto la sospensione. Questo tempo è incluso nelle interruzioni del GC, quindi è utile determinare se le interruzioni lunghe sono causate dalla lentezza del GC o dalla sospensione lenta del thread. Ecco un esempio di tempo normale di sospensione su Nexus 5:
suspend all histogram: Sum: 1.513ms 99% C.I. 3us-546.560us Avg: 47.281us Max: 601us
Esistono altre aree di interesse, tra cui il tempo totale trascorso e il throughput della GC. Esempi:
Total time spent in GC: 502.251ms Mean GC size throughput: 92MB/s Mean GC object throughput: 1.54702e+06 objects/s
Ecco un esempio di come eseguire il dump dei tempi di GC di un'app già in esecuzione:
adb shell kill -s QUIT PID
adb pull /data/anr/anr_2020-07-13-19-23-39-817
A questo punto, i tempi di GC sono inferiori a anr_2020-07-13-19-23-39-817
. Ecco un esempio di output
da 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
Strumenti per analizzare i problemi di correttezza del GC
Vari fattori possono causare arresti anomali in ART. Gli arresti anomali che si verificano durante la lettura o la scrittura nei campi degli oggetti possono indicare un danneggiamento dell'heap. Se il GC si arresta in modo anomalo durante l'esecuzione, potrebbe anche indicare una corruzione dell'heap. La causa più comune della corruzione dell'heap è il codice dell'app errato. Fortunatamente, esistono strumenti per eseguire il debugging degli arresti anomali relativi al GC e all'heap, tra cui le opzioni di verifica dell'heap specificate sopra e CheckJNI.
CheckJNI
CheckJNI è una modalità che aggiunge controlli JNI per verificare il comportamento dell'app. Questi controlli non sono attivati per impostazione predefinita per motivi di prestazioni. I controlli rilevano alcuni errori che potrebbero causare la corruzione dell'heap, come l'utilizzo di riferimenti locali e globali non validi/non aggiornati. Per attivare CheckJNI:
adb shell setprop dalvik.vm.checkjni true
La modalità forzata di CheckJNI è utile per rilevare le scritture oltre la fine delle regioni dell'array. Se questa opzione è attivata, la funzione JNI di accesso all'array restituisce copie con zone rosse. Una zona rossa è una regione all'inizio/alla fine del puntatore restituito che ha un valore speciale, verificato al momento del rilascio dell'array. Se i valori nella zona rossa non corrispondono a quanto previsto, si è verificato un overrun o un underrun del buffer. Questo causa l'interruzione di CheckJNI. Per attivare la modalità forzare copia:
adb shell setprop dalvik.vm.jniopts forcecopy
Un esempio di errore che CheckJNI dovrebbe rilevare è la scrittura oltre la fine di un array ottenuto da GetPrimitiveArrayCritical
. Questa operazione può danneggiare l'heap di Java. Se la scrittura avviene all'interno dell'area della zona rossa di CheckJNI, CheckJNI rileva il problema quando viene chiamato ReleasePrimitiveArrayCritical
corrispondente. In caso contrario, la scrittura danneggia un oggetto casuale nell'heap di Java e può causare un arresto anomalo del GC in futuro. Se la memoria danneggiata è un campo di riferimento, il GC potrebbe rilevare l'errore e stampare il messaggio Tried to mark <ptr> not contained by any spaces (Ho provato a contrassegnare <ptr> come non contenuto da spazi).
Questo errore si verifica quando il gruppo di controllo tenta di contrassegnare un oggetto per il quale non riesce a trovare uno spazio. Se questo controllo non va a buon fine, il GC attraversa le radici e tenta di vedere se l'oggetto non valido è una radice. Da qui, hai due opzioni: L'oggetto è un oggetto principale o non principale.
Esempio di radice non valida
Se l'oggetto è una radice non valida, vengono stampate alcune informazioni utili:
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
In questo caso, vreg=1
all'interno di
com.google.gwt.collections.JavaReadableJsArray.get
dovrebbe contenere un riferimento all'heap, ma contiene un puntatore non valido
dell'indirizzo 0x2
. Questa è una radice non valida. Per eseguire il debugging di questo problema, utilizza oatdump
sul file oat e controlla il metodo con la radice non valida. In questo caso, l'errore si è rivelato essere un bug del compilatore nel backend x86. Ecco il changelist che ha risolto il problema: https://android-review.googlesource.com/#/c/133932/
Esempio di oggetto danneggiato
Se l'oggetto non è un elemento principale, viene stampato un output simile al seguente:
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 la corruzione dell'heap non è una causa non valida, è difficile eseguire il debug. Questo messaggio di errore indica che nell'heap era presente almeno un oggetto che faceva riferimento all'oggetto non valido.