Google стремится продвигать расовую справедливость для черных сообществ. Смотри как.
Эта страница была переведа с помощью Cloud Translation API.
Switch to English

Понимание Systrace

Systrace является основным инструментом для анализа производительности устройств Android. Тем не менее, это действительно обертка вокруг других инструментов. Это оболочка на стороне хоста для atrace , исполняемый файл на стороне устройства, который контролирует трассировку пространства пользователя и устанавливает ftrace , и основной механизм трассировки в ядре Linux. systrace использует atrace для включения трассировки, затем читает буфер ftrace и оборачивает все это в автономный просмотрщик HTML. (В то время как более новые ядра поддерживают пакетный фильтр Linux Enhanced Berkeley (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 запускается на CPU, что-то на CPU должно записывать буфер ftrace, который регистрирует аппаратные изменения. Это означает, что если вам интересно узнать, почему экранное ограждение изменило состояние, вы можете увидеть, что было запущено на ЦП в точную точку его перехода (что-то, запущенное на ЦП, вызвало это изменение в журнале). Эта концепция является основой для анализа производительности с помощью systrace.

Пример: рабочая рамка

В этом примере описывается systrace для обычного конвейера пользовательского интерфейса. Чтобы следовать примеру, загрузите zip-файл трассировок (который также включает другие трассировки, упомянутые в этом разделе), разархивируйте файл и откройте файл systrace_tutorial.html в своем браузере. Имейте в виду, что это systrace - большой файл; если вы не используете systrace в своей повседневной работе, это, вероятно, намного больший след с гораздо большим количеством информации, чем вы когда-либо видели за один след.

Для согласованной периодической рабочей нагрузки, такой как TouchLatency, конвейер пользовательского интерфейса содержит следующее:

  1. EventThread в SurfaceFlinger пробуждает поток пользовательского интерфейса приложения, сигнализируя о том, что пришло время визуализировать новый кадр.
  2. Приложение отображает кадр в потоке пользовательского интерфейса, RenderThread и hwuiTasks, используя ресурсы процессора и графического процессора. Это основная часть емкости, потраченной на пользовательский интерфейс.
  3. Приложение отправляет визуализированный кадр в SurfaceFlinger, используя связыватель, затем SurfaceFlinger переходит в спящий режим.
  4. Второй EventThread в SurfaceFlinger пробуждает SurfaceFlinger для запуска композиции и отображения вывода. Если SurfaceFlinger определит, что не нужно выполнять какую-либо работу, он возвращается в режим сна.
  5. SurfaceFlinger обрабатывает композицию с использованием Hardware Composer (HWC) / Hardware Composer 2 (HWC2) или GL. Композиция HWC / HWC2 быстрее и с меньшим энергопотреблением, но имеет ограничения в зависимости от системы на чипе (SoC). Обычно это занимает ~ 4-6 мс, но может перекрываться с шагом 2, потому что приложения Android всегда имеют тройную буферизацию. (Хотя приложения всегда имеют тройную буферизацию, в SurfaceFlinger может быть только один ожидающий кадр, что делает его идентичным двойной буферизации.)
  6. SurfaceFlinger отправляет окончательный вывод для отображения с драйвером поставщика и возвращается в режим ожидания, ожидая пробуждения EventThread.

Давайте пройдемся по началу кадра в 15409 мс:

Обычный конвейер пользовательского интерфейса с запущенным EventThread
Рисунок 1. Нормальный конвейер пользовательского интерфейса, EventThread работает

Рисунок 1 - это обычный кадр, окруженный нормальными кадрами, поэтому он является хорошей отправной точкой для понимания работы конвейера пользовательского интерфейса. Строка потока пользовательского интерфейса для TouchLatency включает разные цвета в разное время. Столбцы обозначают разные состояния для потока:

  • Серый Спать.
  • Синий. Runnable (он может работать, но планировщик еще не выбрал его для запуска).
  • Зеленый. Активно работает (планировщик считает, что работает).
  • Красный. Бесперебойный сон (как правило, спящий на блокировке в ядре). Может указывать на нагрузку ввода / вывода. Чрезвычайно полезен для устранения проблем с производительностью.
  • Оранжевый. Бесперебойный сон из-за нагрузки ввода / вывода.

Чтобы просмотреть причину бесперебойного сна (доступно из точки sched_blocked_reason sched_blocked_reason), выберите красный срез непрерывного сна.

Во время работы EventThread поток пользовательского интерфейса для TouchLatency становится работоспособным. Чтобы увидеть, что его разбудило, нажмите на синий раздел.

Поток пользовательского интерфейса для TouchLatency
Рисунок 2. Поток пользовательского интерфейса для TouchLatency

На рисунке 2 показан поток пользовательского интерфейса TouchLatency, вызванный tid 6843, что соответствует EventThread. Поток пользовательского интерфейса просыпается, отображает кадр и ставит его в очередь для использования SurfaceFlinger.

Поток пользовательского интерфейса просыпается, отображает кадр и помещает его в очередь для использования SurfaceFlinger
Рисунок 3. Поток пользовательского интерфейса просыпается, отображает кадр и ставит его в очередь для использования SurfaceFlinger

Если в binder_driver включен тег binder_driver , вы можете выбрать транзакцию binder_driver чтобы просмотреть информацию обо всех процессах, участвующих в этой транзакции.

Рисунок 4. Связывающая транзакция

На рисунке 4 показано, что в 15 423,65 мс Binder: 6832_1 в SurfaceFlinger становится работоспособным из-за tid 9579, то есть RenderThread от TouchLatency. Вы также можете увидеть queueBuffer с обеих сторон транзакции связывания.

Во время queueBuffer на стороне SurfaceFlinger количество ожидающих кадров из TouchLatency изменяется от 1 до 2.

Ожидающие кадры идут от 1 до 2
Рисунок 5. Ожидающие кадры идут от 1 до 2

На рисунке 5 показана тройная буферизация, где есть два завершенных кадра, и приложение собирается начать рендеринг третьего. Это потому, что мы уже удалили некоторые кадры, поэтому приложение сохраняет два ожидающих кадра вместо одного, чтобы избежать дальнейших пропущенных кадров.

Вскоре после этого основной поток SurfaceFlinger пробуждается вторым EventThread, поэтому он может вывести на экран более старый ожидающий кадр:

Основной поток SurfaceFlinger разбудил второй EventThread
Рисунок 6. Основной поток SurfaceFlinger пробуждается вторым EventThread

SurfaceFlinger сначала фиксирует старый ожидающий буфер, в результате чего количество ожидающих буферов уменьшается с 2 до 1.

SurfaceFlinger сначала фиксируется на старом ожидающем буфере
Рисунок 7. SurfaceFlinger первым фиксирует старый ожидающий буфер

После фиксации буфера SurfaceFlinger устанавливает композицию и отправляет последний кадр на дисплей. (Некоторые из этих разделов включены как часть точки mdss mdss, поэтому они могут быть не включены в ваш SoC.)

SurfaceFlinger устанавливает композицию и представляет окончательный кадр
Рисунок 8. SurfaceFlinger устанавливает композицию и отправляет последний кадр

Затем mdss_fb0 на ЦП 0. mdss_fb0 - это поток ядра конвейера отображения для вывода визуализированного кадра на дисплей. Мы можем видеть mdss_fb0 как свою собственную строку в трассировке (прокрутите вниз, чтобы просмотреть).

mdss_fb0 просыпается на CPU 0
Рисунок 9. mdss_fb0 просыпается на CPU 0

mdss_fb0 просыпается, ненадолго бежит, входит в непрерывный сон, затем снова просыпается.

Пример: нерабочий кадр

Этот пример описывает systrace, используемый для отладки джиттера Pixel / Pixel XL. Чтобы следовать примеру, загрузите zip-файл трассировок (который включает в себя другие трассировки, упомянутые в этом разделе), разархивируйте файл и откройте файл systrace_tutorial.html в своем браузере.

Когда вы откроете systrace, вы увидите что-то вроде этого:

TouchLatency работает на Pixel XL с большинством включенных опций
Рисунок 10. TouchLatency, работающий на Pixel XL (большинство опций включено, включая точки трассировки mdss и kgsl)

При поиске джанка проверьте строку FrameMissed в SurfaceFlinger. FrameMissed - это улучшение качества жизни, предоставляемое HWC2. При просмотре systrace для других устройств строка FrameMissed может отсутствовать, если устройство не использует HWC2. В любом случае FrameMissed коррелирует с отсутствием в SurfaceFlinger одной из его чрезвычайно регулярных сред выполнения и неизменного количества ожидающих буферов для приложения ( com.prefabulated.touchlatency ) при vsync.

FrameMissed корреляция с SurfaceFlinger
Рисунок 11. Соотношение FrameMissed с SurfaceFlinger

На рисунке 11 показан пропущенный кадр со скоростью 15598,29 мс. SurfaceFlinger кратко проснулся с интервалом vsync и вернулся в режим сна, не выполняя никакой работы, что означает, что SurfaceFlinger решил, что не стоит пытаться снова отправить кадр на дисплей. Зачем?

Чтобы понять, как конвейер вышел из строя для этого фрейма, сначала просмотрите приведенный выше пример рабочего фрейма, чтобы увидеть, как выглядит нормальный конвейер пользовательского интерфейса в systrace. Когда будете готовы, вернитесь к пропущенному кадру и вернитесь назад. Обратите внимание, что SurfaceFlinger просыпается и сразу же идет спать. При просмотре количества ожидающих кадров из TouchLatency, есть два кадра (хороший ключ, чтобы помочь выяснить, что происходит).

SurfaceFlinger просыпается и сразу идет спать
Рисунок 12. SurfaceFlinger просыпается и сразу же засыпает

Поскольку у нас есть кадры в SurfaceFlinger, это не проблема приложения. Кроме того, SurfaceFlinger просыпается в нужное время, поэтому это не проблема SurfaceFlinger. Если SurfaceFlinger и приложение выглядят нормально, возможно, это проблема с драйвером.

Поскольку точки mdss и sync включены, мы можем получить информацию об ограждениях (совместно используемых драйвером дисплея и SurfaceFlinger), которые контролируют отправку кадров на дисплей. Эти ограждения перечислены в разделе mdss_fb0_retire , который обозначает, когда на дисплее отображается рамка. Эти заборы предоставляются как часть категории трассировки sync . То, какие ограждения соответствуют определенным событиям в SurfaceFlinger, зависит от вашего SOC и стека драйверов, поэтому поработайте с вашим поставщиком SOC, чтобы понять значение категорий ограждений в ваших трассах.

mdss_fb0_retire fences
Рисунок 13. Заборы mdss_fb0_retire

На рисунке 13 показан кадр, который отображался в течение 33 мс, а не 16,7 мс, как ожидалось. На полпути через этот фрагмент этот кадр должен был быть заменен новым, но не был. Посмотрите предыдущий кадр и поищите что-нибудь.

Кадр, предшествующий сорванному кадру
Рисунок 14. Кадр, предшествующий сорванному кадру

На рисунке 14 показан 14,482 мс фрейма. Сломанный двухкадровый сегмент составлял 33,6 мс, что примерно соответствует ожидаемому для двух кадров (мы выполняем при 60 Гц, 16,7 мс на кадр, что близко). Но 14,482 мс совсем не близки к 16,7 мс, что говорит о том, что с каналом дисплея что-то не так.

Выясните, где именно заканчивается этот забор, чтобы определить, что его контролирует.

Исследовать конец забора
Рисунок 15. Исследование конца забора

Рабочая очередь содержит __vsync_retire_work_handler , который выполняется при изменении ограждения. Просматривая исходный код ядра, вы можете видеть, что он является частью драйвера дисплея. Похоже, что он находится на критическом пути для конвейера отображения, поэтому он должен работать как можно быстрее. Его можно запустить примерно за 70 человек (не с большой задержкой планирования), но это рабочая очередь, и она может быть не точно запланирована.

Проверьте предыдущий кадр, чтобы определить, способствовал ли он; иногда дрожание может накапливаться со временем и в конечном итоге приводить к пропущенному сроку.

Предыдущий кадр
Рисунок 16. Предыдущий кадр

Работоспособной линия на kworker не видно , потому что зритель поворачивает его белым цветом , когда он выбран, но статистика говорит историю: 2.3 мс задержки планировщика для части трубопровода дисплея критического пути плохо. Перед тем, как продолжить, исправить задержку , которая, перемещая эту часть дисплея трубопровода критического пути от workqueue (который работает как SCHED_OTHER нить CFS) к выделенному SCHED_FIFO KTHREAD. Для этой функции требуются временные гарантии, которые рабочие очереди не могут (и не предназначены) предоставлять.

Это причина джанка? Трудно сказать окончательно. За исключением простых для диагностики случаев, таких как конфликт блокировки ядра, приводящий к сбою критически важных для отображения потоков, трассировки обычно не указывают на проблему. Мог ли этот джиттер быть причиной пропущенного кадра? Абсолютно. Время ограничения должно составлять 16,7 мс, но оно совсем не близко к кадрам, ведущим к пропущенному кадру. Учитывая, насколько тесно связан конвейер дисплея, возможно, что дрожание вокруг таймингов ограждения привело к падению кадра.

В этом примере решение включало преобразование __vsync_retire_work_handler из рабочей очереди в выделенный kthread. Это привело к заметным улучшениям джиттера и уменьшению рывка в тесте на прыгающий шар. Последующие следы показывают, что время забора колеблется очень близко к 16,7 мс.