בדף הזה מוסבר איך לנפות באגים בבעיות של תיקון שגיאות ובבעיות בביצועים של Android Runtime (ART) (אוסף אשפה). במאמר מוסבר איך להשתמש באפשרויות האימות של GC, לזהות פתרונות לכשלים באימות של GC ולמדוד בעיות בביצועים של GC ולטפל בהן.
כדי לעבוד עם ART, אפשר לעיין בדפים בקטע ART ו-Dalvik הזה ובפורמט Dalvik Executable. למידע נוסף על אימות התנהגות האפליקציה, תוכלו לקרוא את המאמר אימות התנהגות האפליקציה בסביבת זמן הריצה של Android (ART).
סקירה כללית על ART GC
ל-ART יש כמה תוכניות GC שונות שמכילות הפעלה של אמצעי איסוף אשפה שונים. החל מגרסה Android 8 (Oreo), תוכנית ברירת המחדל היא העתקה בו-זמנית (CC). התוכנית השנייה של GC היא Concurrent Mark Sweep (CMS).
אלה כמה מהמאפיינים העיקריים של Concurrent Copying GC:
- CC מאפשרת להשתמש במקצה של מצביע-דחיפה שנקרא RegionTLAB. כך מוקצה למחרוזת של כל חוט אפליקציה מאגר הקצאה מקומי לשרשור (TLAB), שמאפשר להקצות אובייקטים מ-TLAB שלו על ידי דחיפת המצביע 'top', בלי סנכרון.
- CC מבצע פינוי אשכול על ידי העתקת אובייקטים בו-זמנית, בלי להשהות את שרשראות האפליקציה. הדבר נעשה בעזרת מחסום קריאה שמנתב קריאות של הפניות מהמקבץ, בלי צורך בהתערבות מצד מפתח האפליקציה.
- ל-GC יש רק השהיה קטנה אחת, שהיא קבועה בזמן בהתאם לגודל האשפה.
- ב-Android מגרסה 10 ואילך, CC מרחיב את היכולות שלו ומאפשר ניהול גרעיני (GC) לפי דורות. הוא מאפשר לאסוף אובייקטים חדשים, שבדרך כלל לא ניתן לגשת אליהם במהירות יחסית, ללא מאמץ רב. כך אפשר להגדיל את תפוקת ה-GC ולהשהות משמעותית את הצורך לבצע GC של אשכול מלא.
מנהל הזיכרון השני ש-ART עדיין תומך בו הוא CMS. מנגנון האיסוף הזה תומך גם בביצוע דחיסה, אבל לא בו-זמנית. לא מתבצעת דחיסה עד שהאפליקציה עוברת לרקע, ואז השרשור של האפליקציה מושהה כדי לבצע דחיסה. דחיסה נדרשת גם כשהקצאת אובייקט נכשלת בגלל פיצול. במקרה כזה, יכול להיות שהאפליקציה תפסיק להגיב למשך זמן מה.
מכיוון שמערכת ניהול התוכן (CMS) מבצעת דחיסה לעיתים רחוקות, ייתכן שאובייקטים פנויים לא יהיו צמודים זה לזה. לכן, המערכת משתמשת במקצה מבוסס-רשימת-פריטים פנויים שנקרא RosAlloc. העלות של הקצאה היא גבוהה יותר בהשוואה ל-RegionTLAB. לבסוף, בגלל הפיצול הפנימי, השימוש בזיכרון של אשכול Java יכול להיות גבוה יותר ב-CMS מאשר ב-CC.
אפשרויות אימות וביצועים ב-GC
שינוי סוג ה-GC
יצרני ציוד מקורי יכולים לשנות את סוג ה-GC. תהליך השינוי כולל הגדרה של משתנה הסביבה ART_USE_READ_BARRIER
בזמן ה-build.
ערך ברירת המחדל הוא true, שמפעיל את האוסף של CC כי הוא משתמש במחסום הקריאה. במערכת ניהול התוכן, צריך להגדיר את המשתנה הזה באופן מפורש כ-false.
כברירת מחדל, האוסף של CC פועל במצב דור ב-Android מגרסה 10 ואילך. כדי להשבית את מצב הדור, אפשר להשתמש בארגומנט שורת הפקודה -Xgc:nogenerational_cc
. לחלופין, אפשר להגדיר את מאפיין המערכת באופן הבא:
adb shell setprop dalvik.vm.gctype nogenerational_cc
אימות ה-heap
אימות אשכול הוא כנראה האפשרות השימושית ביותר של GC לניפוי באגים של שגיאות שקשורות ל-GC או של פגיעה באשכולות. הפעלת אימות ה-heap גורמת ל-GC לבדוק את תקינות ה-heap בכמה נקודות במהלך תהליך איסוף האשפה. לבדיקה של אשכול יש את אותן אפשרויות כמו לבדיקה של שינוי סוג ה-GC. אם האימות של אשכול הנתונים מופעל, הוא מאמת את השורשים ומבטיח שאובייקטים שאפשר לגשת אליהם מפנים רק לאובייקטים אחרים שאפשר לגשת אליהם. כדי להפעיל את האימות של GC, מעבירים את הערכים הבאים של -Xgc
:
- אם האפשרות הזו מופעלת,
[no]preverify
מבצע אימות של אשכול לפני שמתחיל את ה-GC. - אם ההגדרה מופעלת,
[no]presweepingverify
מבצע אימות של אשכול לפני שהוא מתחיל את תהליך הניעור של האוסף האשפה. - אם ההגדרה מופעלת,
[no]postverify
מבצע אימות של אשכול אחרי ש-GC מסיים את הסריקות. [no]preverify_rosalloc
,[no]postsweepingverify_rosalloc
ו-[no]postverify_rosalloc
הן אפשרויות נוספות של GC שמאמתות רק את המצב של החשבונאות הפנימית של RosAlloc. לכן, אפשר להשתמש בהן רק עם האוסף של CMS, שמשתמש במקצה RosAlloc. הדברים העיקריים שאומתים הם שערכים קסומים תואמים למשתני קבועים צפויים, ושכל בלוקים פנויים של זיכרון רשומים במפהfree_page_runs_
.
ביצועים
יש שני כלים עיקריים למדידת ביצועי GC: גרסת dump של תזמון GC ו-Systrace. יש גם גרסה מתקדמת של Systrace שנקראת Perfetto. כדי למדוד בעיות בביצועים של GC באופן חזותי, אפשר להשתמש ב-Systrace וב-Perfetto כדי לקבוע אילו פעולות GC גורמות להשהיות ארוכות או מבטלות את העדיפות של חוטי אפליקציה. אמנם מערכת האיסוף והניהול של האשפה ב-ART השתפרה משמעותית עם הזמן, אבל התנהגות לא טובה של mutator, כמו הקצאה מוגזמת, עדיין עלולה לגרום לבעיות בביצועים
אסטרטגיית איסוף
האיסוף ב-CC GC מתבצע על ידי הפעלת GC לזיכרון זמין או GC של אשכול מלא. באופן אידיאלי, כדאי להריץ את GC הצעיר בתדירות גבוהה יותר. ה-GC מבצע אוספים של CC צעירים עד שהתפוקה (מחושבת לפי בייטים ששוחררו לשנייה במהלך משך ה-GC) של מחזור האיסוף שהסתיים זה עתה נמוכה מהתפוקה הממוצעת של אוספים של CC במחסנית מלאה. במקרה כזה, ה-CC של האשפה המלאה נבחר ל-GC המבוצע בו-זמנית הבא במקום ה-CC של האשפה הצעירה. אחרי שהאוסף של כל הזיכרון ב-heap מסתיים, ה-GC הבא עובר חזרה ל-CC של זיכרון צעיר. אחד הגורמים העיקריים שגורמים לשיטה הזו לפעול הוא ש-CC צעיר לא משתנה אחרי שהוא מסתיים. כתוצאה מכך, אירועי CC של זיכרון חדש מתרחשים יותר ויותר עד שהתפוקה נמוכה יותר מ-CC של אשכול מלא, וכתוצאה מכך האשכול גדל.
שימוש ב-SIGQUIT כדי לקבל מידע על ביצועי GC
כדי לקבל את זמני הביצועים של GC לאפליקציות, שולחים את הפקודה SIGQUIT
לאפליקציות שכבר פועלות, או מעבירים את הפקודה -XX:DumpGCPerformanceOnShutdown
ל-dalvikvm
כשמפעילים תוכנית בשורת הפקודה. כשאפליקציה מקבלת את האות של בקשת ה-ANR (SIGQUIT
), היא מפיקה נתונים שקשורים לנעילת הנעילה, למחסומי השרשור ולביצועי ה-GC שלה.
כדי לקבל דמפים של תזמון GC, משתמשים ב-:
adb shell kill -s QUIT PID
הפקודה הזו יוצרת קובץ (עם התאריך והשעה בשם, למשל anr_2020-07-13-19-23-39-817) ב-/data/anr/
. הקובץ הזה מכיל כמה דמפים של ANR וגם תזמונים של GC. כדי לאתר את זמני ה-GC, מחפשים את האפשרות Dumping cumulative Gc timings. התזמונים האלה מציגים כמה דברים שעשויים לעניין, כולל פרטי ההיסטוגרמה של השלבים וההשהיות של כל סוג 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 PID
adb 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 ותאונות שקשורות ל-heap, כולל אפשרויות האימות של ה-heap שצוינו למעלה ו-CheckJNI.
CheckJNI
CheckJNI הוא מצב שמוסיף בדיקות JNI כדי לאמת את התנהגות האפליקציה. הבדיקות האלה לא מופעלות כברירת מחדל מסיבות שקשורות לביצועים. הבדיקות מזהות כמה שגיאות שעלולות לגרום לזיהום אשכול, כמו שימוש בהפניות מקומיות וגלובאליות לא חוקיות או לא עדכניות. כדי להפעיל את CheckJNI:
adb shell setprop dalvik.vm.checkjni true
מצב ה-forcecopy של CheckJNI שימושי לזיהוי כתיבה מעבר לקצה של אזורי מערך. כשהאפשרות הזו מופעלת, הפונקציות של JNI לגישה למערך מחזירות עותקים עם אזורים אדומים. אזור אדום הוא אזור בסוף או בהתחלה של המצביע המוחזר, עם ערך מיוחד שמאומת כשהמערך משוחרר. אם הערכים באזור האדום לא תואמים למה שצפוי, התרחשה חריגה ממלאי המטמון או מחסור במטמון. כתוצאה מכך, הקריאה ל-CheckJNI תופסק. כדי להפעיל את מצב ה-forcecopy:
adb shell setprop dalvik.vm.jniopts forcecopy
דוגמה לשגיאה ש-CheckJNI אמור לזהות היא כתיבה מעבר לקצה של מערך שהתקבל מ-GetPrimitiveArrayCritical
. הפעולה הזו עלולה לגרום לפגיעה ב-heap של Java. אם הכתיבה נמצאת באזור האדום של CheckJNI, הבעיה תתגלה ב-CheckJNI כשייקרא לפונקציה ReleasePrimitiveArrayCritical
המתאימה. אחרת, הכתיבה גורמת לפגיעה באובייקט אקראי כלשהו ב-heap של Java, ויכולה לגרום לקריסה עתידית של GC. אם הזיכרון הפגום הוא שדה הפניה, יכול להיות ש-GC יזהה את השגיאה וידפיס את השגיאה Tried to mark <ptr> not contained by any spaces.
השגיאה הזו מתרחשת כש-GC מנסה לסמן אובייקט שאין לו מקום. אם הבדיקה הזו נכשלת, ה-GC עובר על השורשים ומנסה לראות אם האובייקט הלא חוקי הוא שורש. מכאן יש שתי אפשרויות: האובייקט הוא אובייקט ברמה הבסיסית (root) או אובייקט שאינו ברמה הבסיסית.
דוגמה לשורש לא תקין
אם האובייקט הוא שורש לא חוקי, מודפס מידע שימושי:
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
במקרה הזה, המשתנה vreg=1
בתוך com.google.gwt.collections.JavaReadableJsArray.get
אמור להכיל הפניה לאוסף, אבל הוא מכיל מצביע לא חוקי לכתובת 0x2
. זהו שורש לא חוקי. כדי לנפות באגים בבעיה הזו, משתמשים ב-oatdump
בקובץ ה-OAT ומחפשים את השיטה עם השורש הלא חוקי. במקרה הזה, התברר שהשגיאה היא באג במהדר בקצה העורפי של 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
כשהפגיעה ב-heap היא לא שורש לא חוקי, קשה לנפות באגים. הודעת השגיאה הזו מציינת שהיה לפחות אובייקט אחד ב-heap שצביע לאובייקט הלא תקין.