logcatを使って、開発中のアプリに関する基本的なパフォーマンス統計を簡単に取得することができます。logcatは、Android OSのログや接続デバイスからのアプリケーションメッセージを、ADBを介して取得します。このトピックではMeta Questログで提供される情報について説明します。その情報は、logcatのタグVrApiとXrPerformanceManagerを使用します。

logcatの使い方については、Logcatをご覧ください。ADBの概要については、ADBをご覧ください。

使用例:

adb logcat -s VrApi,XrPerformanceManager

VrApiログ

Meta Questアプリを実行している接続されたデバイスでlogcatを実行しており、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 %に一致するフレーム毎秒を常に維持しています。アプリスペースワープが有効な場合、このレートはヘッドセットディスプレイのリフレッシュレートの50 %まで低下します。
`Prd=38ms`	予測時間。これは、アプリがレンダリング前にポーズのクエリをした時点から、HMD画面上にフレームが表示される時点までの正味の時間です。予測時間がアプリにおける望ましいゲームプレイ時間の値よりも高い場合は、フレームレートを高くし、レイトラッチングを実装することにより、この値を低くすることができます。
`Tear=0`	過去1秒間での画面ティアリングの数。コンポジターがフレームを送信するのに時間がかかり過ぎると、画面ティアリングが発生します。それを修正するには、コンポジターが実行する必要のある作業量を(表示するオーバーレイレイヤーの量を減らしたり、アプリスペースワープを無効にしたりして)減らしてください。
`Early=0`	必要とされる前に配信されたフレームの数。早期フレームは、余分なレイテンシモードが使用されている場合に発生することがあります。わずかな早期フレームは無視できますが、この数値が常に高い場合は、CPUレベルとGPUレベルが必要以上に高く設定されていないかを確認してください。初期フレームの数がFPSと一致する場合は、追加レイテンシモードをオフにするか、解像度またはシェーダーの複雑性を引き上げることでヘッドルームを活用することをおすすめします。
`Stale=0`	フレームが時間どおりに配信されなかったため、代わりに前のフレームが使われた回数。 CPUとGPUは並行して動作するので、フレームのレンダリングにかかる時間は1フレームの合計時間よりも長くかかる場合がありますが、CPUとGPUのどちらも、単独で1つのフレームより長くかかることはありません。そのため、72 FPSで実行されるアプリでは、1秒あたり72個の期限切れフレームが表示される可能性があります。このような状況では、レンダリングと表示時間のレイテンシは高くなりますが、フレームのリリーステンポは一定です。期限切れフレームが問題になるのは、値が0より大きくリフレッシュレートより小さい場合です。その場合、いずれかのフレームが連続して2回表示されたり、スキップされたりするようになり、ユーザーの操作性が低下します。そのような状況では、追加レイテンシモードを使用することができます。この機能(UnityとUnrealエンジンではデフォルトでオン)は、常に余分のフレームを待機するようにATWに対して指示し、2番目のフレームより後の準備ができていれば、フレームを期限切れと見なさないように指示します。アプリのレンダリングが迅速に実行される場合には早期フレームと見なされますが、すべてスムーズに表示されます。期限切れフレームの仕組みについて詳しくは、Meta Quest、Oculus Go、Gear VRでゲームプレイのレイテンシを理解するのブログ投稿をご覧ください。
`Stale2/5/10/max=0/0/0/0`	連続した2、5、10個のフレームが期限切れになった回数、および過去1秒間に連続して期限切れになった最長連続フレーム数。
`VSnc=1`	フレーム間のvsync数(`swap interval`とも呼ばれる)。Meta Questの開発では、これを常に1に設定してください。2に設定すると、アプリのレンダリングのレートが半分になります。アプリのSpaceWarpを有効にすると、この値が0に設定されます。これは、アプリが独立したFPSで実行されるとみなされるためです。この際、画面が更新されるごとにASWがフレームを生成します。
`Lat=-1`	現在設定されているフレームのタイミングを管理するテクニック。値が>0である場合、アプリにおいてエクストラレイテンシモードが有効化されていることを意味し、レイテンシの余分なフレーム数を示します。値が0の場合、アプリがフェーズ同期もエクストラレイテンシモードも使っていないことを示します。値が<0の場合、アプリがフェーズ同期を使用していることを意味します。-1はデフォルトのフェーズ同期、-2は固定レイテンシフェーズ同期を示し、-3はアプリのSpacewarp用に調整されたパラメーターを使ったフェーズ同期を表します。
`Fov=0`	固定中心窩レンダリング(FFR)の強度レベル。FFRでは、視界の周辺部分のテクスチャーが中心部分より低い解像度でレンダリングされます。これにより、周辺視野でのシーンの忠実度が下がり、GPUの負荷が軽減されます。この数値はGPUのパフォーマンスに直接影響し、レベルが高いと、視覚上のアーティファクトが画面の端で目立ってしまいます。必要なパフォーマンスの改善を得るため、ビジュアル的に最も受け入れられるレベルを選択してください。
`CPU4/GPU=2/2`	アプリによって設定されるCPUとGPUのクロックレベルを指定します。`CPU`の後に続く数値は、測定対象のコアを示します。このレベルは手動で設定できますが、アプリにおいてフレームレートの要求レベルが達成されていない場合、クロックレベルを増加させるダイナミッククロックスロットリングの使用が推奨されます。アプリが要求フレームレートに達していない場合、クロックレベルを見直すことで、パフォーマンスがCPUバウンドかGPUバウンドかを素早く判断でき、最適化のターゲットを絞り込むことができます。例えば、パフォーマンスに問題があるアプリのCPUレベルが4でGPUレベルが2の場合、使用可能なGPUのオーバーヘッドがまだあるので、アプリはCPUバウンドであると判断できます。ただし、どちらのレベルも4でアプリに問題がある場合、この数値はそれほど役に立たないため、期限切れフレーム、アプリのGPU時間、CPU/GPUの使用率などその他の指標を使って、最適化できそうな領域を見つける必要があります。 CPUとGPUクロックレベルの詳細については、電力管理を参照してください。
`1171/441MHz`	CPUとGPUのクロック速度を示します。CPUとGPUのクロックレベルを調整する場合は、これを変更します。CPUとGPUのクロックレベルは直接調整および変更できるため、モニタリングに便利です。これらのレベルに関連付けられているクロック速度はSoCごとに異なり、周波数は変更できません。
`OC=FF`	現在Meta Questヘッドセットに搭載されているCPUでは、そのようなことは発生しなくなりました。コアをオフラインにすることなくコアのエネルギー使用量を削減できるため、この機能は使用されなくなりました。
`TA=0/0/0`	ATW、メイン、レンダリングスレッドの親和性。開発者には、スレッドの親和性を手動で設定しないよう推奨されていますが、これらの値は、スレッドが大きなコアで実行されているかどうかを確認する場合に役立ちます。Meta Questでは、ATWスレッドは0を報告します。
`SP=N/N/N`	ATW、メイン、およびレンダリングスレッドのスケジューリング優先順位。Fは`SCHED_FIFO` (最高優先順位)、Nは`SCHED_NORMAL` (普通の優先順位)を表します。Meta Questでは、ATWは常にNに設定します。Oculus Goでは、ATWはFに設定します。そうしないと、ティアリングが発生する可能性があります。メインおよびレンダリングスレッドのスケジューリング優先順位は、`vrapi_SetPerfThread`を使用してネイティブで設定できます。
`Mem=1804MHz`	メモリの速度。
`Free=2975MB`	Androidによって報告される使用可能なメモリー。Androidでは、メモリの処理方法がやや不透明であるため、この値はおおまかなガイダンスとして使用してください。例えば、アプリがバックグラウンドに下がった場合、新しく前面に出たアプリやOS操作に多くのメモリが引っ張られ、`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`	ATWのGPU時間。これは、ATWがレンダリングにかける時間です。この時間と、使うレイヤー数およびその複雑さとの間には、直接的な相関関係があります。正距円筒レイヤーやシリンダーレイヤーの方がクワッドレイヤーや投影レイヤーよりもGPUコストがかかります。 ATWに時間がかかりすぎると、再生中に画面が裂けてしまいます。
`App=4.51ms`	アプリのGPU時間。これは、GPUがアプリの1つのフレームをレンダリングするために費やす時間です。アプリの最適化にあたっては、この値をモニタリングすることが特に重要です。表示される時間が1つのフレームの時間(72フレーム毎秒の場合は13.88ミリ秒)より長いアプリは、GPUバウンドです。表示時間が1つのフレームの時間より短いアプリは、おそらくCPUバウンドです。この指標は、アプリがGPUバウンドかCPUバウンドかを判断する上で役立つだけでなく、シェーダーの変更時、テクスチャーの追加時、メッシュの変更時、その他の変更時にアプリをモニタリングする場合にも使うことができます。この数値から、GPUに残っているヘッドルームの量を把握できます。また、特定のオブジェクトのオンとオフの切り替えにデバッグロジックを使う場合、それらのオブジェクトがパフォーマンスに与える影響がわかります。
`GD=0.00ms`	境界のGPU時間。これは、境界のレンダリングに使われるGPU時間です。プレイヤーが境界の近くにいない場合、または境界が無効になっている場合、この値は0になります。この数値は操作できませんが、境界に費やされている時間を知りたい場合は役立つかもしれません。
`CPU&GPU=11.04ms`	フレームのレンダリングにかかった時間の合計。これは現在、UnityまたはUnrealエンジンを使用している場合にのみ参照できます。レンダリングまたはRHIスレッドでフレームの処理を開始してからGPUでレンダリングを完了するまでの測定値を表します。この値からアプリのGPU時間(`App`)を引くことで、レンダースレッドのおおよそのクロック時間を判断できます。これは、ボトルネックになっているかどうかを判断する場合に役立ちます。
`LCnt=2(DR72,LM2)`	コンポジターがフレームごとにレンダリングするレイヤー数。システムレイヤー(システムメニューとポップアップ)を含みます。さらに、直接レンダリングFPS (オーバーレイレイヤーのレンダリングに使うもの)、コンポジター速度の最適化のためにマージされたレイヤー数を指定します。同じ設定のレイヤーはコンポジターの中にマージされ、それによりATW GPU時間が短縮されます。
`GPU%=0.43`	GPU使用率。この数値は[0,1]の範囲であることに注意してください。この値が最大値1.0なら、アプリはGPUバウンドです。この値が0.9を超えると、スケジューリングによるパフォーマンスの問題が発生する場合があります。
`CPU%=0.27(W0.36)`	CPU使用率。この数値は[0,1]の範囲であることに注意してください。最初の数値はすべてのCPUコアの平均使用率、2番目の数値は最もパフォーマンスの低いコアの使用率を表します。これらの数値の有用性は、GPU使用率(`GPU%`)ほど高くありません。ほとんどのアプリはマルチスレッドであり、スレッドはスケジューラによって利用可能なコアに割り当てられるので、パフォーマンスが最も低いコアで実行されていない限り、メインスレッドは平均パーセンテージでのみ表示されます。
`DSF=1.00`	DPU (ディスプレイ処理ユニット) 倍率係数。1より大きい値なら、ディスプレイのネイティブ解像度までスケールアップするため、GPUによるフレームデータがDPUによって処理されます。DPUにより色収差補正と鮮明化が実行されて、単純な双線形フィルタリングよりも良い結果になります。
`CFL=19.74/21.66`	過去1秒間のコンポジターフレームレイテンシの最低値/最高値(ミリ秒)。これは、OSコンポジターで費やされる`Prd=`の測定時間を示します。この時間は、送信したフレームを自分のアプリではなく表示用に準備するものです。
`ICFLp95=20.94`	過去の秒の、ミリ秒単位の、統合コンポジターフレーム遅延の正規曲線の95パーセンタイル測定値。この数字は、OSコンポジターの動作の変更効果を比較する上でmin/max CFLよりも便利です。
`LD=0`	ローカルディミングが有効(1)か、無効(0)かを示します。この機能は現在、Quest Proデバイスでのみご利用いただけます。
`SF=1.00`	スケール係数。現在送信しているフレームバッファ解像度と、デバイスの推奨フレームバッファ解像度の比率
`LP=0`	省電力モードが有効(1)か無効(0)か。
`DVFS=0`	動的電圧&周波数スケーリングが有効(1)か、無効(0)かを示します。現時点では、有効になることはありません。

自動フィルタリングが少なくとも1つのレイヤーでスーパーサンプリングまたはシャープニングを選択した場合、以下の値がログ行の末尾に表示されます。

統計情報	説明
`ShrpLCnt=5`	自動フィルタリングによってシャープニングが有効と判断されたレイヤーの数。
`ShrpR=1.000`	グラフィックスガバナーによって決定されたフォビエーション半径。
`SSLCnt=3/3`	グラフィックスガバナーによってスーパーサンプリングされたレイヤーの数/自動フィルタリングアルゴリズムがスーパーサンプリングの効果があると判断したレイヤーの数。

スペースワープが有効の場合、この例に示されているような追加の線が毎秒表示されます。

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

以下の表は、各統計とその解釈の方法について説明しています。

統計情報	説明
`ASW=90`	1秒間にレンダリングされるフレーム数。スペースワープによって生成されるフレームを含みます。
`Type=App`	使われるスペースワープアルゴリズム。アプリスペースワープが有効の場合、これは`App`です。それ以外の場合、自動生成の非同期スペースワープのソースが出力されます。
`E=0.022/0.271`	非同期スペースワープの二乗平均外挿値と二乗平均平方根外挿値。非同期スペースワープアルゴリズムが使われている場合、これらの値はゼロ以外になります。これは、アプリによって、ドロップされたフレームを埋めるためと推測されます。
`D=0.000/0.000`	非同期スペースワープの二乗平均データ外挿値と二乗平均平方根データ外挿値。非同期スペースワープアルゴリズムが使われている場合、これらの値はゼロ以外になります。これは、アプリによって、ドロップされたフレームを埋めるためと推測されます。

XrPerformanceManagerログ

Meta Questアプリを実行している接続されたデバイスでlogcatを実行しており、XrPerformanceManagerタグがフィルターで除外されていない場合、この例のような行が定期的に表示されます。

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

これは、古いCPUレベルとGPUレベルおよび新しく適用されたCPUレベルとGPUレベルを表します。

さらに、CPUレベルとGPUレベルでのデバッグに興味がある開発者は、接続された端末で次のコマンドを実行できます。

adb shell setprop debug.oculus.clockStateLogLevel 1

実行すると、その時点でアプリで利用可能なCPUレベルとGPUレベルの最小レベルと最大レベルの理由を記載した定期的な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が出力され、最小GPUレベルと最大レベルを設定する追加の試みがリスト化されます。これは、動作を変えなかったため無視された試みです。この出力は、特定のCPU/GPUレベルの変化を追跡しようとしていて、上記の手順に従ってそれが表示されなかった場合に役立ちます。次は、clockStateLogLevel 2のlogcat出力の例です。

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

これらのログは、debug.oculus.clockStateLogLevel 0を設定するか、ヘッドセットを再び起動するまで、logcatに出力され続けます。