Logcat предоставляет простой способ получения базовых статистических значений производительности разрабатываемого приложения. Logcat извлекает журналы ОС Android и сообщений приложений с подключенного устройства через Android Debug Bridge (ADB). В этой статье содержится информация, представленная в журналах Meta Quest, в которых используются теги logcat VrApi и PerformanceManager_ZSF.

Информацию об использовании logcat см. в статье Logcat. Информацию об ADB см. в статье ADB.

Пример использования:

adb logcat -s VrApi,XrPerformanceManager

Журналы VrApi

Если logcat выполняется на подключенном устройстве, на котором запущено приложение Meta Quest и не выполняется фильтрация по тегу VrApi, каждую секунду на экране будет появляться примерно следующая строка:

FPS=72/72,Prd=38ms,Tear=0,Early=0,Stale=0,Stale2/5/10/max=0/0/0/0,VSnc=1,Lat=-1,Fov=0,CPU4/GPU=2/2,1171/441MHz,OC=FF,TA=0/0/0,SP=N/N/N,Mem=2092MHz,Free=2975MB,PLS=0,Temp=32.2C/0.0C,TW=1.25ms,App=4.49ms,GD=0.00ms,CPU&GPU=12.96ms,LCnt=2(DR72,LM2),GPU%=0.43,CPU%=0.37(W0.50),DSF=1.00,CFL=19.79/21.54,ICFLp95=20.94,LD=0,SF=1.00,LP=0,DVFS=0,ShrpLCnt=5,ShrpR=1.000,SSLCnt=3/3

В следующей таблице описываются все статистические значения и предоставляются рекомендации по их интерпретации:

Статистическое значение	Описание
`FPS=72/72`	Количество кадров, воспроизводимых в секунду/частота обновления дисплея гарнитуры. Хорошо работающее приложение будет последовательно сообщать о воспроизводимых кадрах в секунду как 100 % частоты обновления дисплея гарнитуры. При включении функции App SpaceWarp произойдет снижение частоты обновления дисплея гарнитуры до 50 %.
`Prd=38ms`	Прогнозируемое время. Это абсолютное время между моментом, когда приложение запрашивает позу перед рендерингом, и моментом отображения кадра на экране гарнитуры. Если прогнозируемое время больше, чем требуется для игрового процесса вашего приложения, увеличение частоты кадров и реализация фиксации с задержкой могут уменьшить это значение.
`Tear=0`	Количество разрывов изображения за последнюю секунду. Разрывы экрана возникают, если компоновщик слишком долго отправляет кадр. Для их устранения уменьшите нагрузку компоновщика (снизьте количество воспроизводимых слоев оверлея или отключите функцию App SpaceWarp).
`Early=0`	Количество кадров, которые были предоставлены раньше, чем они были нужны. Ранние кадры возможны, если используется режим повышенной задержки. Некоторые из них можно игнорировать, но если этот показатель постоянно высок, убедитесь, что уровни ЦП и ГП не заданы выше, чем это нужно. Если количество ранних кадров соответствует количеству кадров в секунду, рекомендуется отключить режим дополнительной задержки или воспользоваться запасом по времени, увеличив разрешение либо сложность шейдера.
`Stale=0`	Количество кадров, которые не были доставлены вовремя, так что вместо них использовался предыдущий кадр. Поскольку ЦП и ГП работают параллельно, иногда рендеринг кадра занимает больше времени, чем общая продолжительность одного кадра, но ни ЦП, ни ГП не занимают больше времени, чем кадр по отдельности. Таким образом, приложение может работать с частотой 72 кадров/с, но при этом иметь 72 устаревших кадра в секунду. В таких ситуациях задержка между временем рендеринга и отображения будет выше, но темп выдачи кадров будет стабильным. Устаревшие кадры становятся проблемой, если это значение больше 0 и меньше частоты обновления. На этом этапе некоторые кадры отображаются два раза подряд, а некоторые кадры пропускаются, что создает негативные впечатления у пользователя. В таких ситуациях можно использовать режим повышенной задержки. Эта функция (включена в Unity и Unreal Engine по умолчанию) указывает функции асинхронного искажения временной шкалы всегда ждать дополнительный кадр и не считать кадры устаревшими, если они не готовы после второго кадра. Если приложение отрисовывается быстро, кадр будет считаться ранним, но всё будет выглядеть гладко. Подробнее о том, как работают устаревшие кадры, см. в записи Understanding Gameplay Latency for Meta Quest, Oculus Go and Gear VR (Задержка игрового процесса в Meta Quest, Oculus Go и Gear VR) в блоге.
`Stale2/5/10/max=0/0/0/0`	Несколько раз последовательные кадры 2, 5 и 10 были устаревшими и самой длинной чередой таких последовательных кадров за последнюю секунду.
`VSnc=1`	Количество vsyncs между кадрами (также называемое кодом `swap interval`). Если вы разрабатываете приложения для Meta Quest, для этого показателя практически всегда должно быть установлено значение 1, поскольку значение 2 может снизить частоту рендеринга вдвое. При включении функции App SpaceWarp для этого показателя следует устанавливать значение 0, поскольку, когда функция ASW генерирует кадры при каждом обновлении дисплея, приложение должно работать с независимым количеством кадров в секунду.
`Lat=-1`	Текущая настройка метода управления синхронизацией кадров. Значение > 0 указывает на то, что в приложении включен режим дополнительной задержки. Здесь указывается количество дополнительных кадров задержки. Значение 0 указывает на то, что приложение не использует ни режим синхронизации колебаний, ни режим дополнительной задержки. Значение < 0 указывает на то, что ваше приложение использует режим синхронизации колебаний. Значение -1 означает синхронизацию колебаний по умолчанию, -2 — с фиксированной задержкой, а -3 — с параметрами, измененными для функции App Spacewarp.
`Fov=0`	Уровень интенсивности фиксированного фовеального рендеринга (FFR). Функцию FFR можно использовать для рендеринга текстур по краям глаза с меньшим разрешением, чем в центре, что снижает достоверность сцены в периферийном зрении зрителя и уменьшает нагрузку на ГП. Это число напрямую влияет на производительность ГП, и на более высоких уровнях по краям экрана будут заметны видимые артефакты. Выберите наиболее визуально приемлемый уровень для необходимого повышения производительности.
`CPU4/GPU=2/2`	Уровни тактовой частоты ЦП и ГП, установленные приложением. Число, следующее после `CPU`, указывает на ядро, для которого проводятся измерения. Эти уровни можно установить вручную, однако рекомендуется использовать динамическое регулирование тактовой частоты, которое увеличивает значения, если приложение не достигает нужного уровня частоты кадров. Если приложение не достигает нужного уровня частоты кадров, проверка уровней тактовой частоты поможет быстро определить, связана ли производительность с ЦП или ГП, чтобы выявить целевую область для оптимизации. Например, если в приложении имеются с проблемы результативности и оно использует уровни ЦП 4 и ГП 2, то, по всей видимости, оно привязано к ЦП, поскольку ресурсы ГП всё ещё доступны. Однако если оба процессора работают на уровне 4 и в приложении есть проблемы, это число не так полезно, и для поиска потенциальных областей оптимизации следует использовать другие показатели, например устаревшие кадры, время ГП приложения и использование ЦП и ГП. Подробнее об уровнях тактовой частоты ЦП и ГП см. в статье Управление энергопотреблением.
`1171/441MHz`	Тактовые частоты ЦП и ГП, которые изменяются при настройке уровней тактовой частоты ЦП и ГП. Тактовые частоты ЦП и ГП более удобно отслеживать, поскольку их можно регулировать и изменять напрямую. Тактовые частоты, привязанные к этим уровням, варьируются в разных системах, и их частоты нельзя менять.
`OC=FF`	Нынешние процессоры в гарнитурах Meta Quest больше не поддерживают эту функцию и могут снижать энергопотребление ядер без их отключения, поэтому эта функция больше не используется.
`TA=0/0/0`	Привязка к вычислительным ядрам потока асинхронного искажения временной шкалы, главного потока и потока рендеринга. Рекомендуется, чтобы разработчики избегали устанавливать вручную свойства потока, однако эти значения полезны для проверки того, что ваши потоки работают на больших ядрах. В Meta Quest поток асинхронного искажения временной шкалы будет сообщать 0.
`SP=N/N/N`	Приоритетность по графику потоков асинхронного искажения временной шкалы, главного потока и потока и рендеринга. F — это `SCHED_FIFO`, то есть самый высокий приоритет, а N — это `SCHED_NORMAL` для обычного приоритета. На Meta Quest асинхронное искажение временной шкалы должно всегда быть N. На Oculus Go асинхронное искажение временной шкалы должно быть F, иначе могут происходить разрывы. Приоритет планирования основного потока и потока рендеринга можно задать в нативном формате с помощью `vrapi_SetPerfThread`.
`Mem=1804MHz`	Скорость памяти.
`Free=2975MB`	Свободная память, отображаемая Android. В Android память обрабатывается не вполне ясно, поэтому это значение полезно лишь для общего представления. Например, если приложение переходит в фоновый режим, то переведенное на передний план приложение и операции ОС будут использовать большой объем памяти, что может привести к сбою приложения, даже если `Free` сообщает о наличии доступной памяти. Это значение наиболее полезно для отслеживания того, что память выделяется быстрее, чем ожидалось, или не освобождается в ожидаемое время.
`PLS=0`	Текущий уровень питания устройства. Сообщается об уровнях `NORMAL` (0), `SAVE` (1) и `DANGER` (2). По мере нагрева устройства уровень питания будет автоматически меняться с `NORMAL` на `SAVE` и в итоге на `DANGER`. При достижении уровня `DANGER` откроется диалоговое окно с предупреждением о перегреве. Приложения должны отслеживать уровень питания и менять режим, снижая затраты на рендеринг при переходе в режим энергосбережения. Подробнее об этом см. в статье Управление энергопотреблением.
`Temp=32.2C/0.0C`	Температура батареи и датчиков. Эти значения были особенно важны для разработки VR-приложений с использованием телефонов. В случае появления проблем с температурой на Meta Quest значение `PLS` можно использовать в качестве индикатора влияния температуры на работу устройства.
`TW=1.27ms`	Время работы ГП в режиме асинхронного искажения временной шкалы означает время, используемое асинхронным искажением временной шкалы для рендеринга. Это время напрямую зависит от количества используемых слоев и их сложности: равнопрямоугольные и цилиндрические слои требуют больше ресурсов ГП, чем слои четырехугольников и проекционные. Слишком длительное асинхронное искажение временной шкалы может привести к разрывам экрана при воспроизведении.
`App=4.51ms`	Время ГП приложения, то есть время, затраченное ГП на отрисовку одного кадра приложения. Это одно из самых полезных отслеживаемых значений при оптимизации приложения. Если время превышает длительность одного кадра (13,88 мс для 72 кадров в секунду), это означает, что приложение привязано к ГП. Если это время меньше длины кадра, приложение, скорее всего, привязано к ЦП. Эту метрику также полезно отслеживать при изменении шейдеров, добавлении текстур, изменении сеток и внесении других изменений. Она позволяет понять, сколько свободных ресурсов осталось у ГП, а если для включения и выключения определенных объектов используется отладочная логика, можно определить, насколько эти объекты требовательны к производительности.
`GD=0.00ms`	Граничное время ГП, которое представляет собой время графического процессора, используемое при рендеринге границ. Если игрок не находится вблизи своей границы или граница отключена, это значение будет равно 0. Это значение не подразумевает никаких действий, но вам может быть интересно узнать, сколько времени использует граница.
`CPU&GPU=11.04ms`	Общее время, необходимое для рендеринга кадра. Эта метрика пока доступна только при использовании платформ Unity и Unreal Engine и измеряется с момента начала обработки кадра потоком рендеринга или RHI до момента завершения рендеринга графическим процессором. Если вычесть из этого значения время ГП приложения (`App`), можно определить приблизительное время работы потока рендеринга, что поможет понять, не представляет ли он проблему.
`LCnt=2(DR72,LM2)`	Количество слоев, рендеринг которых компоновщик выполняет за кадр, в том числе системных (т. е. системных меню и всплывающих окон). Дополнительно указываются частота кадров прямого рендеринга (используется для рендеринга наложенных слоев) и количество слоев, которые были объединены для оптимизации скорости работы компоновщика. Слои, имеющие одинаковые настройки, совмещаются в компоновщике, сокращая время асинхронного искажения временной шкалы ГП.
`GPU%=0.43`	Процент использования ГП. Обратите внимание, что это число находится в пределах [0,1]. Если это значение достигает 1,0, приложение привязано к графическому процессору. Если это число превышает 0,9, могут возникнуть проблемы производительности, связанные с графиком.
`CPU%=0.27(W0.36)`	Процент использования ЦП. Обратите внимание: это число находится в пределах [0,1]. Первое число — это средний процент использования всех ядер ЦП, а второе — процент использования ядра с наименьшей производительностью. Эти значения менее полезны, чем процент использования графического процессора (`GPU%`). Поскольку большинство приложений многопоточны, а планировщик назначает потоки любому доступному ядру, основной поток может быть представлен только в среднем проценте, если только он не выполняется на ядре с наименьшей производительностью.
`DSF=1.00`	Фактор масштабирования блока обработки дисплея (DPU). Если значение >1, данные кадра, поступающие от графического процессора, обрабатываются блоком DPU для масштабирования до собственного разрешения дисплея. Блоки DPU выполняют коррекцию хроматической аберрации и повышение резкости, обеспечивая лучшие результаты, чем простая билинейная фильтрация.
`CFL=19.74/21.66`	Минимальная/максимальная задержка кадра компоновщика в миллисекундах за последнюю секунду. Это указывает на количество времени в измерении `Prd=`, затрачиваемое на компоновщик ОС, который подготавливает отправленный вами кадр к отображению, а не ваше собственное приложение.
`ICFLp95=20.94`	95-й процентиль измерения нормальной кривой задержки кадра интегрированного компоновщика, в миллисекундах, за последнюю секунду. Это число более полезно для сравнения влияния изменений на поведение компоновщика ОС, чем мин./макс. значение CFL.
`LD=0`	Включено (1) или выключено (0) локальное затемнение. Сейчас эта функция доступна только на устройствах Quest Pro.
`SF=1.00`	Коэффициент масштаба. Соотношение разрешения буфера кадра, которое вы в данный момент отправляете, к рекомендуемому разрешению буфера кадра вашего устройства.
`LP=0`	Режим энергосбережения: включен (1) или отключен (0).
`DVFS=0`	Включено (1) или отключено (0) динамическое масштабирование напряжения и частоты. В настоящее время оно никогда не включается.

Если при автоматической фильтрации используется избыточная выборка и повышение резкости хотя бы на одном слое, в конце строки журнала будут указаны следующие значения:

Статистическое значение	Описание
`ShrpLCnt=5`	Количество слоев, на которых функция автоматической фильтрации определяет необходимость повышения резкости.
`ShrpR=1.000`	Радиус фовеации, определяемый регулятором графики.
`SSLCnt=3/3`	Количество слоев, для которых регулятор графики использует избыточную выборку, или количество слоев, которые алгоритм автоматической фильтрации определяет как способные получить пользу при использовании избыточной выборки.

Если функция SpaceWarp включена, каждую секунду будет отображаться дополнительная строка, подобная показанной в следующем примере:

ASW=90, Type=App E=0.022/0.271,D=0.000/0.000

Статистическое значение	Описание
`ASW=90`	Количество кадров в секунду, для которых выполняется рендеринг, в том числе кадров, сгенерированных при использовании функции SpaceWarp.
`Type=App`	Используемый алгоритм SpaceWarp. Это `App`, если функция App SpaceWarp включена; в противном случае указывается источник для автоматически генерируемой функции Async SpaceWarp.
`E=0.022/0.271`	Средние и среднеквадратические значения экстраполяции для Async Spacewarp. Обратите внимание, что эти значения не равны нулю при использовании алгоритма Async Spacewarp, который, скорее всего, заполняет кадры, пропущенные приложением.
`D=0.000/0.000`	Средние и среднеквадратические значения экстраполяции данных для Async Spacewarp. Обратите внимание, что эти значения не равны нулю при использовании алгоритма Async Spacewarp, который, скорее всего, заполняет кадры, пропущенные приложением.

Журналы XrPerformanceManager

Если logcat выполняется на подключенном устройстве, где запущено приложение Meta Quest, и метка XrPerformanceManager не отфильтрована, периодически будет отображаться строка, подобная показанной в следующем примере:

SetClockLevels: Apply pending clock request change: 4,3 -> 3,3

Это обозначает активированные ранее и вновь уровни ЦП и ГП.

Кроме того, разработчики, которых интересует отладка уровней ЦП и ГП, могут выполнить следующую команду в подключенном терминале:

adb shell setprop debug.oculus.clockStateLogLevel 1

В результате этого периодически будет создаваться журнал logcat с перечислением причин минимального и максимального уровней загрузки ЦП и ГП, доступных вашему приложению в данный момент, например:

CPU clock level updates
Min [level=4 reason="Application-Set ProcessorPerformanceLevel threshold."]
Max [level=4 reason="Set max CPU level for performance profile."]
Current [level=4 reason="Requesting CPU level based on Utilization."]
Final Level = 4

GPU clock level updates
Min [level=3 reason="Application-Set ProcessorPerformanceLevel threshold."]
Max [level=4 reason="Set max GPU level for performance profile."]
Max [level=5 reason="Enabling the dynamic resolution boost"] (FORCED)
Current [level=3 reason="Request GPU level based on Utilization."]
Final Level = 3

Кроме того, разработчики могут увеличить clockStateLogLevel, например:

adb shell setprop debug.oculus.clockStateLogLevel 2

В результате этого будет создаваться журнал logcat с указанием дополнительных попыток установить минимальный и максимальный уровни ГП, которые были проигнорированы из-за отсутствия изменений в поведении. Эта информация может быть полезна, если вы пытаетесь отследить определенное изменение уровня ЦП/ГП и не видите его при выполнении вышеуказанных шагов. Ниже показан пример информации из журнала logcat с clockStateLogLevel 2:

CPU clock level updates
Min [level=4 reason="Application-Set ProcessorPerformanceLevel threshold."]
Max [level=4 reason="Set max CPU level for performance profile."]
Max [level=5 reason="Clamp to max allowed hardware level."] (REJECTED)
Current [level=4 reason="Requesting CPU level based on Utilization."]
Final Level = 4

GPU clock level updates
Min [level=3 reason="Application-Set ProcessorPerformanceLevel threshold."]
Max [level=4 reason="Set max GPU level for performance profile."]
Max [level=5 reason="Enabling the dynamic resolution boost"] (FORCED)
Max [level=7 reason="Clamp to max allowed hardware level."] (REJECTED)
Current [level=3 reason="Request GPU level based on Utilization."]
Final Level = 3

Эти журналы будут отображаться в logcat до тех пор, пока вы не установите debug.oculus.clockStateLogLevel 0 или не перезагрузите гарнитуру.