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 в разное время включает разные цвета. Столбики обозначают различные состояния потока:
- Серый . Спит.
- Синий. Работоспособен (он может работать, но планировщик еще не выбрал его для запуска).
- Зеленый. Активно работает (планировщик считает, что он запущен).
- Красный. Бесперебойный сон (обычно сон при блокировке ядра). Может указывать на нагрузку ввода-вывода. Чрезвычайно полезно для устранения проблем с производительностью.
- Апельсин. Непрерывный сон из-за нагрузки ввода-вывода.
Чтобы просмотреть причину непрерывного сна (доступна из точки трассировки 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. Вы также можете увидеть очередьBuffer на обеих сторонах транзакции связывания.
Во время очередиBuffer на стороне 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. При просмотре системной трассировки для других устройств строка FrameMissed может отсутствовать, если устройство не использует HWC2. В любом случае FrameMissed коррелирует с отсутствием у SurfaceFlinger одной из своих чрезвычайно регулярных сред выполнения и неизменным счетчиком ожидающих буферов для приложения ( com.prefabulated.touchlatency ) при vsync.
На рисунке 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 k. Эта функция нуждается в гарантиях синхронизации, которые рабочие очереди не могут (и не предназначены) предоставить.
Это причина зависания? Трудно сказать окончательно. За исключением легко диагностируемых случаев, таких как конфликты за блокировку ядра, вызывающие спящий режим потоков, критически важных для отображения, трассировки обычно не указывают на проблему. Могло ли это дрожание быть причиной потери кадра? Абсолютно. Время ограничения должно составлять 16,7 мс, но оно совсем не близко к этому значению в кадрах, предшествующих пропущенному кадру. Учитывая, насколько тесно связан конвейер отображения, вполне возможно, что дрожание таймингов привело к пропаданию кадра.
В этом примере решение включало преобразование __vsync_retire_work_handler из рабочей очереди в выделенный поток kthread. Это привело к заметному уменьшению джиттера и уменьшению рывков при тестировании отскакивающего мяча. Последующие трассировки показывают, что время ограничения колеблется очень близко к 16,7 мс.