На этой странице рассказывается, как отлаживать сборку мусора в среде выполнения Android (ART), чтобы устранять проблемы с корректностью и производительностью. В нем рассказывается, как использовать варианты проверки GC, выявлять причины сбоев проверки GC, а также измерять и устранять проблемы с производительностью GC.
Чтобы работать с ART, ознакомьтесь с информацией в разделе ART и Dalvik и формате исполняемого файла Dalvik. Дополнительную информацию о проверке поведения приложений можно найти в статье Как проверить поведение приложения в среде выполнения Android (ART).
Обзор сборщика мусора ART
В ART есть несколько планов сборки мусора, которые состоят из запуска разных сборщиков мусора. В Android 8 (Oreo) и более поздних версиях по умолчанию используется план "Параллельное копирование" (CC). Другой план сборки мусора – Concurrent Mark Sweep (CMS).
Вот основные характеристики Concurrent Copying GC:
- CC позволяет использовать распределитель указателей на буфер, называемый RegionTLAB. Каждому потоку приложения выделяется локальный буфер (TLAB), из которого он может выделять объекты, перемещая указатель top без синхронизации.
- Сборщик мусора CC выполняет дефрагментацию кучи, одновременно копируя объекты без приостановки потоков приложения. Это достигается с помощью барьера чтения, который перехватывает чтение ссылок из кучи без необходимости вмешательства со стороны разработчика приложения.
- В GC есть только одна небольшая пауза, которая не зависит от размера кучи.
- В Android 10 и более поздних версиях CC является сборщиком мусора с поддержкой поколений. Это позволяет без особых усилий собирать молодые объекты, которые часто становятся недоступными довольно быстро. Это позволяет увеличить пропускную способность сборщика мусора и значительно отложить необходимость полной сборки мусора.
Другой сборщик мусора, который по-прежнему поддерживается ART, – это CMS. Этот сборщик мусора также поддерживает сжатие, но не одновременно с другими операциями. Сжатие не выполняется, пока приложение не перейдет в фоновый режим. В этот момент потоки приложения приостанавливаются, чтобы выполнить сжатие. Сжатие также необходимо, когда выделение объекта не удается из-за фрагментации. В этом случае приложение может перестать отвечать на запросы на некоторое время.
Поскольку CMS редко сжимает память, а значит, свободные объекты могут быть не смежными, она использует распределитель на основе списка свободных блоков под названием RosAlloc. У него более высокая стоимость распределения по сравнению с RegionTLAB. Наконец, из-за внутренней фрагментации использование памяти для кучи Java может быть выше для CMS, чем для CC.
Варианты подтверждения и эффективности GC
Как изменить тип сборщика мусора
Производители оригинального оборудования могут менять тип GC. Чтобы изменить его, задайте переменную среды ART_USE_READ_BARRIER во время сборки.
По умолчанию установлено значение true, которое включает сборщик CC, поскольку он использует барьер чтения. В CMS эту переменную следует явно установить в значение false.
По умолчанию сборщик субтитров работает в режиме поколений на устройствах с Android 10 и более поздних версий. Чтобы отключить режим поколений, можно использовать аргумент командной строки -Xgc:nogenerational_cc. Также можно задать системное свойство следующим образом:
adb shell setprop dalvik.vm.gctype nogenerational_cc
Проверка кучи
Проверка кучи, вероятно, самый полезный вариант сборки мусора для отладки ошибок, связанных со сборкой мусора или повреждением кучи. Если включить проверку кучи, сборщик мусора будет проверять ее корректность в нескольких точках процесса сбора мусора. Для проверки кучи используются те же параметры, что и для изменения типа сборки мусора. Если эта функция включена, при проверке кучи проверяются корни и гарантируется, что доступные объекты ссылаются только на другие доступные объекты. Проверка GC включается при передаче следующих значений -Xgc:
- Если правило включено,
[no]preverifyвыполняет проверку кучи перед запуском сборщика мусора. - Если этот параметр включен,
[no]presweepingverifyвыполняет проверку кучи перед запуском процесса очистки сборщика мусора. - Если правило включено,
[no]postverifyвыполняет проверку кучи после того, как сборщик мусора завершит сканирование. [no]preverify_rosalloc,[no]postsweepingverify_rosallocи[no]postverify_rosalloc– это дополнительные параметры сборщика мусора, которые проверяют только внутреннюю статистику RosAlloc. Поэтому они применимы только к сборщику CMS, который использует распределитель RosAlloc. В основном проверяется, соответствуют ли магические значения ожидаемым константам и зарегистрированы ли все свободные блоки памяти в картеfree_page_runs_.
Эффективность
Для оценки производительности сборки мусора есть два основных инструмента: дампы времени сборки мусора и Systrace. Также существует расширенная версия Systrace – Perfetto. Чтобы визуально оценить проблемы с производительностью сборщика мусора, используйте Systrace и Perfetto. Они помогут определить, какие сборщики мусора вызывают длительные паузы или прерывают потоки приложений. Хотя сборщик мусора ART значительно улучшился, неправильное поведение мутатора, например чрезмерное выделение памяти, по-прежнему может вызывать проблемы с производительностью.
Стратегия сбора данных
Сборщик мусора CC GC собирает мусор, запуская молодой сборщик мусора или сборщик мусора всего хипа. Желательно, чтобы молодой сборщик мусора запускался чаще. Сборщик мусора выполняет сборку мусора в молодом поколении до тех пор, пока пропускная способность (рассчитывается как количество освобожденных байтов в секунду за время сборки мусора) только что завершенного цикла сборки не станет меньше средней пропускной способности сборки мусора в полной куче. В этом случае для следующей параллельной сборки мусора будет выбран полный цикл сборки мусора, а не сборка мусора в молодом поколении. После того как сборка всего хипа будет завершена, следующая сборка мусора будет снова выполняться с помощью сборщика молодого поколения. Ключевой фактор, обеспечивающий эффективность этой стратегии, заключается в том, что молодой сборщик мусора не корректирует ограничение размера кучи после завершения работы. Это приводит к тому, что сборка мусора в молодом поколении происходит все чаще и чаще, пока пропускная способность не станет ниже, чем при сборке мусора в полной куче, что в конечном итоге приводит к росту кучи.
Как получить информацию об эффективности сборки мусора с помощью SIGQUIT
Чтобы получить данные о производительности сборщика мусора для приложений, отправьте SIGQUIT уже запущенным приложениям или передайте -XX:DumpGCPerformanceOnShutdown в dalvikvm при запуске программы из командной строки. Когда приложение получает сигнал запроса ANR (SIGQUIT), оно сохраняет информацию, связанную с блокировками, стеками потоков и производительностью сборщика мусора.
Чтобы получить дампы времени сборки мусора, используйте:
adb shell kill -s QUIT PID
Будет создан файл (с датой и временем в названии, например anr_2020-07-13-19-23-39-817) в каталоге /data/anr/. Этот файл содержит дампы ANR и данные о времени сборки мусора. Чтобы найти временные метки сборки мусора, выполните поиск по запросу Dumping cumulative Gc timings. Эти временные показатели могут быть полезны, например, для просмотра информации о гистограмме для каждого типа сборки мусора и ее фаз и пауз. Обычно важнее смотреть на паузы. Пример:
young concurrent copying paused: Sum: 5.491ms 99% C.I. 1.464ms-2.133ms Avg: 1.830ms Max: 2.133ms
Это означает, что средняя пауза составляла 1,83 мс, что достаточно мало, чтобы не вызывать пропуски кадров в большинстве приложений.
Ещё один интересный показатель – время приостановки, которое показывает, сколько времени требуется потоку, чтобы достичь точки приостановки после того, как сборщик мусора запросит приостановку. Это время включается в паузы сборки мусора, поэтому оно позволяет определить, чем вызваны длительные паузы – медленной сборкой мусора или медленной приостановкой потока. Вот пример нормального времени приостановки на устройстве 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
Вот пример того, как получить данные о времени работы сборщика мусора для уже запущенного приложения:
adb shell kill -s QUIT PIDadb pull /data/anr/anr_2020-07-13-19-23-39-817
На этом этапе время работы сборщика мусора находится в пределах 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
Инструменты для анализа проблем с корректностью сборки мусора
Сбои в ART могут происходить по разным причинам. Сбои при чтении или записи в поля объектов могут указывать на повреждение кучи. Если сборщик мусора аварийно завершает работу, это также может указывать на повреждение кучи. Чаще всего повреждение кучи происходит из-за неправильного кода приложения. К счастью, существуют инструменты для отладки сбоев, связанных со сборкой мусора и кучей, включая указанные выше параметры проверки кучи и CheckJNI.
CheckJNI
CheckJNI – это режим, в котором добавляются проверки JNI для подтверждения поведения приложения. По умолчанию он отключен, чтобы не снижать производительность. Проверки выявляют некоторые ошибки, которые могут привести к повреждению кучи, например использование недействительных или устаревших локальных и глобальных ссылок. Чтобы включить CheckJNI:
adb shell setprop dalvik.vm.checkjni true
Режим forcecopy в CheckJNI полезен для обнаружения записи за пределами области массива. Если этот параметр включен, функции JNI для доступа к массивам возвращают копии с красными зонами. Красная зона – это область в начале или конце возвращенного указателя, имеющая специальное значение, которое проверяется при освобождении массива. Если значения в красной зоне не соответствуют ожидаемым, значит произошло переполнение или опустошение буфера. В этом случае CheckJNI прерывает работу. Чтобы включить режим принудительного копирования:
adb shell setprop dalvik.vm.jniopts forcecopy
Пример ошибки, которую должна обнаружить CheckJNI, – запись за пределы массива, полученного от GetPrimitiveArrayCritical. Эта операция может повредить кучу Java. Если запись находится в красной зоне CheckJNI, то CheckJNI обнаруживает проблему при вызове соответствующего метода ReleasePrimitiveArrayCritical. В противном случае запись повредит случайный объект в куче Java и может привести к сбою сборщика мусора. Если поврежденная память является ссылочным полем, сборщик мусора может обнаружить ошибку и вывести сообщение Tried to mark <ptr> not contained by any spaces (Попытка пометить <ptr>, не содержащийся ни в одном пространстве).
Эта ошибка возникает, когда сборщик мусора пытается пометить объект, для которого не может найти место. Если проверка не пройдена, сборщик мусора проходит по корням и пытается определить, является ли недействительный объект корнем. Есть два варианта: объект является корневым или нет.
Пример недопустимого корневого домена
Если объект является недопустимым корневым объектом, выводится полезная информация:
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
Если повреждение кучи не является недопустимым корнем, отладка будет сложной. Это сообщение об ошибке означает, что в куче есть хотя бы один объект, указывающий на недействительный объект.