本頁介紹如何除錯 Android 運行時 (ART) 垃圾收集 (GC) 正確性和效能問題。它解釋瞭如何使用 GC 驗證選項、確定 GC 驗證失敗的解決方案以及測量和解決 GC 效能問題。
若要使用 ART，請參閱ART 和 Dalvik部分以及Dalvik 可執行檔格式中的頁面。有關驗證應用程式行為的其他協助，請參閱驗證 Android 運行時 (ART) 上的應用行為。
ART GC 概述
ART 有一些不同的 GC 計劃，其中包括運行不同的垃圾收集器。從 Android 8 (Oreo) 開始，預設計畫是並發複製 (CC)。另一個 GC 計劃是並發標記清除 (CMS)。
並發複製 GC 的一些主要特徵包括：
- CC 允許使用稱為 RegionTLAB 的凹凸指針分配器。這會為每個應用程式執行緒分配一個執行緒本地分配緩衝區 (TLAB)，然後應用程式執行緒可以透過碰撞「頂部」指針從其 TLAB 中分配對象，而無需任何同步。
- CC 透過並發複製物件而不暫停應用程式執行緒來執行堆疊碎片整理。這是在讀取屏障的幫助下實現的，讀取屏障攔截來自堆的引用讀取，而不需要應用程式開發人員的任何干預。
- GC 只有一次小暫停，該暫停在時間上與堆大小有關。
- CC 在 Android 10 及更高版本中擴展為分代 GC。它可以收集年輕的對象，這些對象通常很快就變得無法訪問，而且不費什麼力氣。這有助於提高 GC 吞吐量並顯著延遲執行全堆 GC 的需要。
ART 仍然支援的另一個 GC 是 CMS。此 GC 還支援壓縮，但不能同時支援。在應用程式進入背景之前，會避免壓縮，此時應用程式執行緒將暫停以執行壓縮。當物件分配由於碎片而失敗時，壓縮也變得必要。在這種情況下，應用程式可能會在一段時間內變得無響應。
由於 CMS 很少壓縮，因此空閒物件可能不連續，因此它使用基於空閒列表的分配器，稱為 RosAlloc。與 RegionTLAB 相比，它的分配成本更高。最後，由於內部碎片，CMS 的 Java 堆記憶體使用量可能高於 CC。
GC 驗證和效能選項
更改 GC 類型
OEM 可以更改 GC 類型。更改過程涉及在建置時設定ART_USE_READ_BARRIER環境變數。預設值為 true，這會啟用 CC 收集器，因為它使用讀取屏障。對於 CMS，變數應明確設定為 false。
預設情況下，CC 收集器在 Android 10 及更高版本中以分代模式運作。若要停用分代模式，可以使用-Xgc:nogenerational_cc命令列參數。或者，可以如下設定係統屬性：
adb shell setprop dalvik.vm.gctype nogenerational_ccCMS 收集器始終以分代模式運作。
驗證堆疊
堆驗證可能是調試 GC 相關錯誤或堆損壞的最有用的 GC 選項。啟用堆驗證會導致 GC 在垃圾收集過程中的幾個點檢查堆的正確性。堆驗證與更改 GC 類型的選項具有相同的選項。如果啟用，堆驗證將驗證根並確保可到達的物件僅引用其他可到達的物件。透過傳入以下-Xgc值來啟用 GC 驗證：
- 如果啟用，
[no]preverify在啟動 GC 之前執行堆驗證。 - 如果啟用，
[no]presweepingverify在開始垃圾收集器清理程序之前執行堆驗證。 - 如果啟用，
[no]postverify在 GC 完成掃描後執行堆疊驗證。 -
[no]preverify_rosalloc、[no]postsweepingverify_rosalloc和[no]postverify_rosalloc是附加 GC 選項，僅驗證 RosAlloc 內部記帳的狀態。因此，它們僅適用於使用 RosAlloc 分配器的 CMS 收集器。驗證的主要內容是 magic 值與預期常數匹配，並且空閒記憶體區塊全部註冊在free_page_runs_映射中。
表現
有兩種主要工具可以測量 GC 效能：GC 時序轉儲和 Systrace。 Systrace 還有一個進階版本，稱為 Perfetto。衡量 GC 效能問題的直覺方法是使用 Systrace 和 Perfetto 來確定哪些 GC 導致長時間暫停或搶佔應用程式執行緒。儘管 ART GC 隨著時間的推移有了顯著改進，但不良的變異行為（例如過度分配）仍然會導致效能問題
採集策略
CC GC 透過運行年輕 GC 或全堆 GC 進行收集。理想情況下，年輕 GC 運作得更頻繁。 GC 執行年輕 CC 收集，直到剛完成的收集週期的吞吐量（以釋放的位元組數/GC 持續時間秒計算）小於全堆 CC 收集的平均吞吐量。發生這種情況時，下一次並發 GC 將選擇全堆 CC，而不是年輕 CC。全堆回收完成後，下一次GC會切換回年輕CC。使該策略發揮作用的關鍵因素是年輕的 CC 在完成後不會調整堆佔用空間限制。這會導致年輕CC發生得越來越頻繁，直到吞吐量低於全堆CC，最終導致堆疊成長。
使用 SIGQUIT 獲取 GC 性能信息
若要取得應用程式的 GC 效能計時，請在啟動命令列程式時向已執行的應用程式傳送SIGQUIT或將-XX:DumpGCPerformanceOnShutdown傳遞給dalvikvm 。當應用程式收到 ANR 請求訊號 ( SIGQUIT ) 時，它會轉儲與其鎖定、執行緒堆疊和 GC 效能相關的資訊。
若要取得 GC 計時轉儲，請使用：
adb shell kill -s QUIT PID
這會在/data/anr/中建立一個檔案（名稱中包含日期和時間，例如 anr_2020-07-13-19-23-39-817）。該文件包含一些 ANR 轉儲以及 GC 計時。您可以透過搜尋轉儲累積 Gc 計時來尋找 GC 計時。這些計時顯示了一些可能感興趣的內容，包括每種 GC 類型的階段和暫停的直方圖資訊。停頓通常更重要。例如：
young concurrent copying paused: Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms
這表明平均暫停時間為 1.83 毫秒，這應該足夠低，不會導致大多數應用程式丟失幀，因此不應成為問題。
另一個值得關注的領域是掛起時間，它測量在 GC 請求掛起之後線程到達掛起點所需的時間。該時間包含在 GC 暫停中，因此有助於確定長時間暫停是否是由 GC 緩慢或線程掛起緩慢引起的。以下是 Nexus 5 上正常掛起時間的範例：
suspend all histogram: Sum: 1.513ms 99% C.I. 3us-546.560us Avg: 47.281us Max: 601us
還有其他令人感興趣的領域，包括花費的總時間和 GC 吞吐量。例子：
Total time spent in GC: 502.251ms Mean GC size throughput: 92MB/s Mean GC object throughput: 1.54702e+06 objects/s
以下是如何轉儲已執行應用程式的 GC 計時的範例：
adb shell kill -s QUIT PIDadb pull /data/anr/anr_2020-07-13-19-23-39-817
此時，GC 計時位於anr_2020-07-13-19-23-39-817內部。以下是 Google 地圖的輸出範例：
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
分析GC正確性問題的工具
有多種因素可能導致 ART 內部崩潰。讀取或寫入物件欄位時發生的崩潰可能表示堆損壞。如果 GC 在運作時崩潰，也可能表示堆損壞。堆損壞的最常見原因是不正確的應用程式程式碼。幸運的是，有一些工具可以調試 GC 和堆相關的崩潰，包括上面指定的堆驗證選項和 CheckJNI。
檢查JNI
CheckJNI是一種添加JNI檢查來驗證應用程式行為的模式；出於效能原因，預設情況下不啟用這些。這些檢查會捕獲一些可能導致堆損壞的錯誤，例如使用無效/過時的本機和全域參考。要啟用 CheckJNI：
adb shell setprop dalvik.vm.checkjni true
CheckJNI 的強制複製模式對於偵測超出陣列區域末端的寫入非常有用。啟用後，forcecopy 會導致陣列存取 JNI 函數傳回帶有紅色區域的副本。紅色區域是傳回指標結尾/開頭的區域，具有特殊值，在釋放數組時會驗證該值。如果紅色區域中的值與預期不匹配，則發生緩衝區溢位或欠載。這會導致 CheckJNI 中止。若要啟用強制複製模式：
adb shell setprop dalvik.vm.jniopts forcecopy
CheckJNI 應捕獲的錯誤範例是寫入超過從GetPrimitiveArrayCritical取得的陣列的末尾。此操作可能會損壞 Java 堆。如果寫入位於 CheckJNI 紅色區域內，則 CheckJNI 在呼叫對應的ReleasePrimitiveArrayCritical時捕獲該問題。否則，寫入會損壞 Java 堆中的某些隨機對象，並可能導致未來的 GC 崩潰。如果損壞的記憶體是引用字段，則 GC 可能會捕獲錯誤並列印錯誤Tried to mark <ptr> not contains by any paths 。
當 GC 嘗試標記找不到空間的物件時，會發生此錯誤。檢查失敗後，GC 會遍歷根並嘗試查看無效物件是否為根。從這裡，有兩個選項： 物件是根物件或非根物件。
無效的根範例
在物件是無效根的情況下，它會列印一些有用的信息： 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
在這種情況下， com.google.gwt.collections.JavaReadableJsArray.get內部的vreg=1應該包含堆引用，但包含地址0x2的無效指標。這是無效的根。若要偵錯此問題，請對 oat 檔案使用oatdump並查看具有無效根的方法。在本例中，該錯誤被證明是 x86 後端中的編譯器錯誤。這是修復它的更改清單： https ://android-review.googlesource.com/#/c/133932/
損壞的物件範例
如果該物件不是根，則輸出類似於以下內容：
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
當堆損壞不是無效根時，就很難調試。此錯誤訊息表示堆中至少有一個物件指向無效物件。