systrace — это основной инструмент для анализа производительности Android-устройств. Однако на самом деле это оболочка для других инструментов. Это оболочка на стороне хоста для atrace , исполняемый файл на стороне устройства, который управляет трассировкой пользовательского пространства и настраивает ftrace , а также основной механизм трассировки в ядре Linux. systrace использует atrace для включения трассировки, затем считывает буфер ftrace и помещает все это в автономную программу просмотра HTML. (Хотя в более новых ядрах есть поддержка Linux Enhanced Berkeley Packet Filter (eBPF), следующая документация относится к ядру 3.18 (без eFPF), поскольку именно оно использовалось в Pixel/Pixel XL.)
systrace принадлежит командам Google Android и Google Chrome и является частью проекта Catapult с открытым исходным кодом. Помимо systrace, Catapult включает в себя и другие полезные утилиты. Например, ftrace имеет больше функций, чем могут быть непосредственно включены systrace или atrace, и содержит некоторые расширенные функции, которые имеют решающее значение для отладки проблем с производительностью. (Для этих функций требуется root-доступ и часто новое ядро.)
Запуск системной трассы
При отладке джиттера на Pixel/Pixel XL начните со следующей команды:
./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000
В сочетании с дополнительными точками трассировки, необходимыми для активности графического процессора и конвейера отображения, это дает вам возможность отслеживать от пользовательского ввода до кадра, отображаемого на экране. Установите большой размер буфера, чтобы избежать потери событий (поскольку без большого буфера некоторые ЦП не содержат событий после некоторой точки трассировки).
Проходя через systrace, имейте в виду, что каждое событие запускается чем-то на ЦП .
Поскольку systrace построен поверх ftrace, а ftrace работает на ЦП, что-то на ЦП должно записывать буфер ftrace, который регистрирует аппаратные изменения. Это означает, что если вам интересно, почему экранное ограждение изменило состояние, вы можете увидеть, что выполнялось на ЦП в точной точке его перехода (что-то, работающее на ЦП, вызвало это изменение в журнале). Эта концепция лежит в основе анализа производительности с помощью systrace.
Пример: рабочая рама
В этом примере описывается системная трасса для обычного конвейера пользовательского интерфейса. Чтобы следовать примеру, загрузите ZIP-файл трассировок (который также включает другие трассировки, упомянутые в этом разделе), разархивируйте файл и откройте файл systrace_tutorial.html в браузере. Имейте в виду, что эта системная трасса представляет собой большой файл; если вы не используете systrace в своей повседневной работе, это, вероятно, гораздо более крупная трассировка с гораздо большим количеством информации, чем вы когда-либо видели в одной трассировке.
Для согласованной периодической рабочей нагрузки, такой как TouchLatency, конвейер пользовательского интерфейса содержит следующее:
- EventThread в SurfaceFlinger пробуждает поток пользовательского интерфейса приложения, сигнализируя о том, что пришло время отрисовать новый кадр.
- Приложение визуализирует кадр в потоке пользовательского интерфейса, RenderThread и hwuiTasks, используя ресурсы ЦП и ГП. Это основная часть ресурсов, затрачиваемых на пользовательский интерфейс.
- Приложение отправляет визуализированный кадр в SurfaceFlinger с помощью связующего, после чего SurfaceFlinger переходит в спящий режим.
- Второй EventThread в SurfaceFlinger пробуждает SurfaceFlinger для запуска композиции и отображения выходных данных. Если SurfaceFlinger определяет, что работы больше нет, он снова переходит в спящий режим.
- SurfaceFlinger обрабатывает композицию с помощью Hardware Composer (HWC)/Hardware Composer 2 (HWC2) или GL. Композиция HWC/HWC2 быстрее и потребляет меньше энергии, но имеет ограничения в зависимости от системы на кристалле (SoC). Обычно это занимает ~4-6 мс, но может совпадать с шагом 2, потому что приложения Android всегда имеют тройную буферизацию. (Хотя приложения всегда имеют тройную буферизацию, в SurfaceFlinger может быть только один ожидающий кадр, что делает его идентичным двойной буферизации.)
- SurfaceFlinger отправляет окончательный вывод для отображения с помощью драйвера поставщика и снова переходит в спящий режим, ожидая пробуждения EventThread.
Давайте пройдемся по кадру, начиная с 15409 мс:
На рис. 1 показан обычный фрейм, окруженный обычными фреймами, так что это хорошая отправная точка для понимания того, как работает конвейер пользовательского интерфейса. Строка потока пользовательского интерфейса для TouchLatency имеет разные цвета в разное время. Полосы обозначают различные состояния потока:
- серый . Спать.
- Синий. Runnable (может работать, но планировщик еще не выбрал его для запуска).
- Зеленый. Активно работает (планировщик думает, что он запущен).
- Красный. Непрерывный сон (обычно сон на блокировке ядра). Может указывать на нагрузку ввода-вывода. Чрезвычайно полезно для отладки проблем с производительностью.
- Апельсин. Непрерывный сон из-за нагрузки ввода-вывода.
Чтобы просмотреть причину непрерывного сна (доступную из точки sched_blocked_reason ), выберите красный фрагмент непрерывного сна.
Во время работы EventThread поток пользовательского интерфейса для TouchLatency становится доступным для выполнения. Чтобы увидеть, что его разбудило, нажмите на синюю секцию.
На рис. 2 показано, что поток пользовательского интерфейса TouchLatency был разбужен tid 6843, что соответствует EventThread. Поток пользовательского интерфейса просыпается, визуализирует кадр и ставит его в очередь для использования SurfaceFlinger.
Если тег binder_driver включен в трассировке, вы можете выбрать транзакцию связывателя, чтобы просмотреть информацию обо всех процессах, участвующих в этой транзакции.
На рис. 4 показано, что через 15 423,65 мс Binder:6832_1 в SurfaceFlinger становится работоспособным из-за tid 9579, который является RenderThread TouchLatency. Вы также можете увидеть queueBuffer на обеих сторонах транзакции связывателя.
Во время queueBuffer на стороне SurfaceFlinger количество ожидающих кадров от TouchLatency увеличивается с 1 до 2.
На рис. 5 показана тройная буферизация, когда есть два завершенных кадра, и приложение вот-вот начнет рендеринг третьего. Это связано с тем, что мы уже отбросили несколько кадров, поэтому приложение хранит два ожидающих кадра вместо одного, чтобы попытаться избежать дальнейшего отбрасывания кадров.
Вскоре после этого основной поток SurfaceFlinger пробуждается вторым EventThread, чтобы он мог вывести на дисплей более старый ожидающий кадр:
SurfaceFlinger сначала фиксирует старый ожидающий буфер, что приводит к уменьшению количества ожидающих буферов с 2 до 1.
После фиксации буфера SurfaceFlinger настраивает композицию и отправляет последний кадр на дисплей. (Некоторые из этих разделов включены как часть точки mdss , поэтому они могут быть не включены в вашу SoC.)
Затем mdss_fb0 пробуждается на ЦП 0. mdss_fb0 — это поток ядра конвейера отображения для вывода визуализированного кадра на дисплей. Мы можем видеть mdss_fb0 как отдельную строку в трассировке (прокрутите вниз, чтобы просмотреть).
mdss_fb0 просыпается, работает ненадолго, переходит в непрерывный сон, затем снова просыпается.
Пример: нерабочий кадр
В этом примере описывается системная трасса, используемая для отладки джиттера Pixel/Pixel XL. Чтобы следовать примеру, загрузите zip-файл с трассировками (который включает в себя другие трассировки, упомянутые в этом разделе), разархивируйте файл и откройте файл systrace_tutorial.html в браузере.
Когда вы откроете системную трассу, вы увидите что-то вроде этого:
При поиске джанка проверьте строку FrameMissed в разделе SurfaceFlinger. FrameMissed — это улучшение качества жизни, предоставляемое HWC2. При просмотре systrace для других устройств строка FrameMissed может отсутствовать, если устройство не использует HWC2. В любом случае FrameMissed коррелирует с тем, что у SurfaceFlinger отсутствует одна из его чрезвычайно регулярных сред выполнения и неизменный счетчик ожидающих буферов для приложения ( com.prefabulated.touchlatency ) при вертикальной синхронизации.
На рис. 11 показан пропущенный кадр на 15598,29 мс. SurfaceFlinger ненадолго проснулся в интервале вертикальной синхронизации и снова заснул, не выполнив никакой работы, что означает, что SurfaceFlinger решил, что не стоит пытаться снова отправить кадр на дисплей. Почему?
Чтобы понять, как сломался конвейер для этого фрейма, сначала просмотрите приведенный выше пример рабочего фрейма, чтобы увидеть, как обычный конвейер пользовательского интерфейса отображается в systrace. Когда будете готовы, вернитесь к пропущенному кадру и работайте в обратном направлении. Обратите внимание, что SurfaceFlinger просыпается и сразу же переходит в спящий режим. При просмотре количества ожидающих кадров от TouchLatency есть два кадра (хороший ключ, помогающий понять, что происходит).
Поскольку у нас есть фреймы в SurfaceFlinger, это не проблема приложения. Кроме того, SurfaceFlinger просыпается в нужное время, так что это не проблема SurfaceFlinger. Если SurfaceFlinger и приложение выглядят нормально, возможно, это проблема с драйвером.
Поскольку mdss и точки трассировки sync включены, мы можем получить информацию о барьерах (общих между драйвером дисплея и SurfaceFlinger), которые контролируют, когда кадры отправляются на дисплей. Эти ограничения перечислены в mdss_fb0_retire , что означает, когда кадр отображается на дисплее. Эти ограничения предоставляются как часть категории трассировки sync . Какие барьеры соответствуют конкретным событиям в SurfaceFlinger, зависит от вашего SOC и стека драйверов, поэтому обратитесь к поставщику SOC, чтобы понять значение категорий барьеров в ваших трассировках.
На рис. 13 показан кадр, который отображался 33 мс, а не 16,7 мс, как ожидалось. В середине этого фрагмента этот кадр должен был быть заменен новым, но этого не произошло. Просмотрите предыдущий кадр и найдите что-нибудь.
На рис. 14 показан кадр длительностью 14,482 мс. Сломанный сегмент из двух кадров составил 33,6 мс, что примерно соответствует ожиданиям для двух кадров (мы рендерим с частотой 60 Гц, 16,7 мс на кадр, что близко). Но 14,482 мс вовсе не близко к 16,7 мс, что говорит о том, что что-то очень не так с конвейером дисплея.
Исследуйте, где именно заканчивается этот забор, чтобы определить, что его контролирует.
Рабочая очередь содержит __vsync_retire_work_handler , который запускается при изменении границы. Просматривая исходный код ядра, вы можете увидеть, что это часть драйвера дисплея. Похоже, что он находится на критическом пути для конвейера отображения, поэтому он должен работать как можно быстрее. Его можно запустить на 70 человек или около того (небольшая задержка планирования), но это рабочая очередь, и ее расписание может быть неточным.
Проверьте предыдущий кадр, чтобы определить, внес ли он свой вклад; иногда дрожание может накапливаться со временем и в конечном итоге привести к пропущенному сроку.
Выполняемая строка на kworker не видна, потому что средство просмотра делает ее белой, когда она выбрана, но статистика говорит об этом: 2,3 мс задержки планировщика для части критического пути конвейера отображения — это плохо . Прежде чем продолжить, исправьте задержку, переместив эту часть критического пути конвейера отображения из рабочей очереди (которая выполняется как поток SCHED_OTHER CFS) в выделенный поток SCHED_FIFO SCHED_FIFO. Эта функция требует временных гарантий, которые рабочие очереди не могут (и не предназначены) предоставить.
Это причина дергания? Трудно сказать окончательно. За исключением легко диагностируемых случаев, таких как конкуренция за блокировку ядра, приводящая к спячке критически важных для отображения потоков, трассировка обычно не указывает на проблему. Могло ли это дрожание быть причиной пропущенного кадра? Абсолютно. Время ограничения должно быть 16,7 мс, но оно совсем не близко к этому в кадрах, предшествующих пропущенному кадру. Учитывая, насколько тесно связан конвейер отображения, вполне возможно, что дрожание вокруг таймингов ограничения привело к пропущенному кадру.
В этом примере решение заключалось в преобразовании __vsync_retire_work_handler из рабочей очереди в выделенный kthread. Это привело к заметному улучшению джиттера и уменьшению рывков в тесте с прыгающим мячом. Последующие трассировки показывают временные ограничения, которые колеблются очень близко к 16,7 мс.