ניפוי באגים לאיסוף אשפה ב-ART

בדף הזה מוסבר איך לנפות באגים באיסוף אשפה של Android Runtime (ART) (GC) בעיות בנכונות ובביצועים. מוסבר איך להשתמש באימות GC אפשרויות שונות, לזהות פתרונות לכשלים באימות GC, ולמדוד לטפל בבעיות ביצועים של GC.

כדי לעבוד עם ART, אפשר לעיין בדפים בART ו-Dalvik ובפורמט Dalvik Executable. לעזרה נוספת באימות ההתנהגות של אפליקציות, אפשר לעיין במאמר אימות בהתנהגות של האפליקציה בסביבת זמן הריצה של Android (ART).

סקירה כללית על ART GC

ל-ART יש כמה תוכניות GC שונות שכוללות הרצת אשפה שונה אספנות. החל מ-Android 8 (Oreo), תוכנית ברירת המחדל היא העתקה בו-זמנית (CC). תוכנית GC האחרת היא סריקה בו-זמנית (CMS).

הנה כמה מהתווים המרכזיים של העתקה בו-זמנית של GC:

• בעזרת CC, אפשר להשתמש במקצה נקודת עצירה (Bump-point) שנקרא RegionTLAB. הפעולה הזו תקצה שרשור מקומי מאגר נתונים זמני להקצאה (TLAB) לכל שרשור של אפליקציה, שיכול להקצות אובייקטים מחוץ ל-TLAB שלו על ידי הקפצה בפסגה את מצביע העכבר, ללא סנכרון.
• הקוד מבצע איחוי של הזיכרון באמצעות העתקה של אובייקטים בו-זמנית בלי להשהות שרשורים של אפליקציות. הפעולה הזו מתבצעת בעזרת מחסום קריאה שמיירט קריאות של הפניה ערימה שלמה, ללא צורך בהתערבות של מפתח האפליקציה.
• ב-GC יש רק השהיה אחת קטנה באופן קבוע ביחס לגודל הערימה.
• CC מתרחב בתור GC מדור קודם ב-Android 10 ואילך. הוא מאפשר לאסוף אובייקטים צעירים, שלרוב לא ניתן להגיע אליהם די מהר, במאמץ מינימלי. המידע הזה עוזר באמצעות הגדלת התפוקה של GC ועיכוב משמעותי לצורך ביצוע GC במלואו.

סוג GC האחר שעדיין נתמך ב-ART הוא CMS. הזה GC תומך גם בדחיסה, אבל לא בו-זמנית. המערכת נמנעת מדחיסה עד שהאפליקציה עובר לרקע, בזמן שהשרשורים של האפליקציות מושהים כדי לבצע דחיסה. הדחיסה נחוצה גם כשהקצאת אובייקט נכשלת עקב פרגמנטציה. כאן ויכול להיות שהאפליקציה תפסיק להגיב למשך זמן מה.

מאחר שמערכת ניהול התוכן קומפקטית לעתים רחוקות, ולכן אובייקטים חופשיים לא יהיו רציפים, היא משתמשת מקצה חופשי בשם RosAlloc. עלות ההקצאה שלו גבוהה יותר בהשוואה אל RegionTLAB. לבסוף, בגלל פיצול פנימי, השימוש בזיכרון של ערימת Java הוא בשימוש יכול להיות גבוה יותר במערכת ניהול התוכן מאשר ב-CC.

אפשרויות לאימות ולביצועים של GC

שינוי הסוג של GC

יצרני ציוד מקורי יכולים לשנות את סוג GC. תהליך השינוי כוללת הגדרה של משתנה הסביבה ART_USE_READ_BARRIER בזמן ה-build. ערך ברירת המחדל הוא True, וזה מפעיל את אוסף הכתוביות בזמן שהוא משתמש במחסום הקריאה. אם מדובר במערכת ניהול תוכן, צריך להגדיר את המשתנה באופן מפורש כ-False.

כברירת מחדל, אוסף הכתוביות פועל במצב גנרטיבי ב-Android 10 ואילך. שפת תרגום להשבית מצב גנרציה, הארגומנט -Xgc:nogenerational_cc של שורת הפקודה בשימוש. לחלופין, אפשר להגדיר את מאפיין המערכת כך:

adb shell setprop dalvik.vm.gctype nogenerational_cc

אוסף ה-CMS תמיד פועל במצב גנרציה.

אימות תמונת הערימה

אימות ערימה הוא ככל הנראה האפשרות השימושית ביותר ב-GC לניפוי באגים שגיאות שקשורות ל-GC או פגיעה בערימה (heap). הפעלה של אימות ערימה גורמת ל-GC כדי לבדוק את נכונות הערימה בכמה נקודות במהלך האשפה תהליך האיסוף. התכונה 'אימות ערימה' כוללת את אותן אפשרויות כמו האפשרויות לשנות את סוג 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, תזמון GC ו-Systrace. קיימת גם גרסה מתקדמת של Systrace, בשם Perfetto. הדרך החזותית למדוד בעיות ביצועים של GC היא להשתמש ב-Systrace ו-Perfetto כדי לקבוע אילו GCs גורמים להשהיות ארוכות הקדמה של שרשורי אפליקציות. למרות ש-ART GC השתפר באופן משמעותי עם הזמן, אובייקט שינוי גרוע התנהגות מסוימת, כגון הקצאה מוגזמת, עדיין עלולה לגרום לבעיות בביצועים

אסטרטגיית איסוף

CC אוסף תמונות וסרטונים על ידי הפעלת GC צעיר או GC מלא. הכי אידיאלית מופעלת בתדירות גבוהה יותר. ה-GC מבצע איסוף של עותקים צעירים עד לתפוקה (מחושב לפי בייטים חופשי/שנייה של משך GC) של מחזור האיסוף הנוכחי שהסתיים נמוך מהתפוקה הממוצעת של אוספי כתוביות מלאים בערימה. במצב כזה, הכתוביות המלאות ייבחרו לאחר GC בו-זמנית במקום CC צעיר. אחרי שאיסוף הערימה המלאה יושלם, כרטיס GC השתנה חזרה ל'עותק צעיר'. אחד מהגורמים העיקריים לכך שהשיטה הזו עובדת הוא שכתוביות צעירים לא משנה את המגבלה של טביעת הרגל הפחמנית לאחר השלמת הפעולה. זה גורם לכך שכתוביות צעירים יופיעו יותר ובתדירות גבוהה יותר עד שהתפוקה תהיה נמוכה יותר מכמות עותקים גדולה מדי, שבסופו של דבר תגדל הערימה.

שימוש ב-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 באמצעות חיפוש של השלכה של תזמוני Gc מצטברים. התזמונים האלה מציג כמה דברים שעשויים לעניין אותך, כולל נתוני ההיסטוגרמה של השלבים וההשהיות של כל סוג GC. בדרך כלל חשוב יותר לבדוק את ההשהיות at. לדוגמה:

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 איטי או שה-thread ואז להשעות אותו לאט. דוגמה לזמן רגיל להשעיה ב-Nexus 5:

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

יש תחומים מעניינים אחרים, כולל משך הזמן הכולל ושיעורי ההמרה תפוקה. לדוגמה:

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 קורסת בזמן ההפעלה, היא עלולה גם להצביע על פגיעה של הזיכרון (heaping). הסיבה השכיחה ביותר לפגיעה בערימה היא קוד שגוי של האפליקציה. למרבה המזל, יש כלים שמאפשרים לנפות באגים ב-GC ובקריסות שקשורות לערימה, כולל האפשרויות לאימות הזיכרון (heap verification) שצוינו שלמעלה, ו-CheckJNI.

צ'ק-ג'יני

CheckJNI הוא מצב שמוסיף בדיקות JNI כדי לאמת את ההתנהגות של האפליקציה; המודעות האלה לא מופעלות על ידי כברירת מחדל מסיבות של ביצועים. בבדיקות מתבצעות כמה שגיאות שעלולות לגרום לפגיעה במצב הערימה (heap), למשל, שימוש בהפניות מקומיות וגלובליות לא תקינות או לא עדכניות. כדי להפעיל את CheckJNI:

adb shell setprop dalvik.vm.checkjni true

מצב ההעתקה המאולצת של CheckJNI יכול לעזור לך לזהות נכתבת מעבר לסוף של אזורי מערך. כשהאפשרות הזו מופעלת, forcecopy גורם למערך לגשת לפונקציות JNI כדי להחזיר עותקים עם אזורים אדומים. אדום תחום (zone) הוא אזור בסוף/בהתחלה של הסמן שמוחזר, שיש לו ערך מיוחד, המאומת כאשר משוחרר. אם הערכים האזור האדום לא תואם למצופה, יש חריגה ממאגר הנתונים הזמני או חוסר חריגות. פעולה זו תגרום ל-CheckJNI לבטל. כדי להפעיל מצב העתקה מוקדמת:

adb shell setprop dalvik.vm.jniopts forcecopy

דוגמה לשגיאה ש-CheckJNI צריך לקלוט היא כתיבה אחרי סוף מערך שהתקבל מ-GetPrimitiveArrayCritical. הפעולה הזו יכול להשחית את ערימת ה-Java. אם הכתיבה היא באזור האזור האדום CheckJNI, ואז CheckJNI מזהה את הבעיה קוראים לפונקציה ReleasePrimitiveArrayCritical התואמת. אחרת, הכתיבה תשחית אובייקט אקראי כלשהו את הערימה של Java ועלולה לגרום לקריסה של GC בעתיד. אם הזיכרון פגום הוא שדה הפניה, וה-GC עשוי לקלוט את השגיאה ולהדפיס את השגיאה ניסיון ל- סימון <ptr> לא כלול ברווחים.

השגיאה הזו מתקבלת כשה-GC מנסה לסמן אובייקט שהוא לא יכול לסמן. למצוא מרחב בשבילו. לאחר שהבדיקה נכשלת, ה-GC עובר את השורשים ומנסה צריך לבדוק אם האובייקט הלא חוקי הוא שורש. בשלב הזה, יש שתי אפשרויות: האובייקט הוא אובייקט Root או אובייקט שאינו Root.

דוגמה בסיסית לא חוקית

במקרה שבו האובייקט הוא הרמה הבסיסית (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. הערך הבסיסי (root) לא תקין. שפת תרגום לנפות באגים בבעיה, להשתמש ב-oatdump בקובץ oat ולבדוק ב-method עם השורש הלא חוקי. במקרה הזה, השגיאה להיות באג מהדר בקצה העורפי של x86. הנה רשימת השינויים שתקנה זאת: https://android-review.googlesource.com/#/c/133932/

דוגמה לאובייקט פגום

אם האובייקט הוא לא Root, פלט דומה לזה הדפסים:

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

אם הפגיעה במצב הערימה היא לא הרמה הבסיסית (root) לא תקינה, קשה יותר לנפות באגים. הודעת השגיאה הזו מציינת שהיה לפחות אובייקט אחד בערימה שמצביעה על האובייקט הלא חוקי.