Help us understand the problem. What is going on with this article?

【Unity】CPU Profilerの結果を分析できる「Profile Analyzer」が便利という話

この記事は【unityプロ技②】 Advent Calendar 2019の7日目の記事です。

今年の春ぐらいにCPU Profilerの結果を分析できるProfile Analyzerと言うツールのPreview版が公開されました。
こちらはパフォーマンスの最適化を行う上では結構便利な機能であり、Previewと言えども個人的には結構使っていけそうな雰囲気があります。

ただ、このツールに関する日本語の情報をあまり見受けない?印象があったので1、今回は紹介序に各種機能などを簡単に解説して行ければと思います。

検証環境

Unity version

  • Unity 2018.4.13f1+
    • Documents曰く「Unity5.6以降」 までは互換性があるとのこと。(PackageManagerの管理下よりコピーしてくれば動作するらしい?)

Packages version

  • Profile Analyzer 0.5.0-preview.1
    • ※執筆時点での最新バージョン

※注意点

便利と言えどもパッケージ自体はまだpreviewです。
将来的な変更で記事中の内容と合わなくなる点が出てくるかもしれないので、その点のみご了承ください。

後は内容的に「Unityの既存のProfiler(以降、Unity Profilerと表記)」に関する前知識がある程度必要となってきますが、記事中ではUnity Profilerに関する基礎的なところからは触れないのでご了承ください。
(一応参考資料だけ載せておきます。)

TL;DR

このツールは何?

  • Unity Profilerの拡張機能(と呼べるかもしれない)
    • なので立ち位置的にはUnity Profilerを置き換える「全く新しいProfiler」とかでは無い
  • 解析対象はCPU Profiler
  • 出来ることからして「Profilerの結果を分析(Analyze)する為のツール」と言えそう

ツールで出来ること

一言で言うと「Unity Profilerで計測したCPUプロファイリング結果の分析/比較」が可能。
後は分析結果をCSVとして出力可能。

★ 単一データの分析

  • プロファイリング結果から「任意のフレーム範囲」を指定して分析
    • e.g. 300フレーム中の「120~149フレーム → 計30フレーム」を指定して分析
  • 分析した複数フレームにまたがる処理時間(ms)の「平均値・中央値・最大値・最小値」などを視覚化

「単一データの分析」では1つのプロファイリング結果を分析して、複数フレームにまたがる処理時間の中央値や平均値などを簡単に算出/視覚化することが出来ます。

★ データの比較

  • 2つのプロファイリング結果を比較
    • 分析結果(平均値/中央値/etc..)の差分(diff)を簡単にチェック可能
  • 比較することで「組み込んだ最適化処理」の効果などが確認しやすくなる
    • 最適化を組み込んだ影響(他の処理負荷など)の再発見に繋がったりも
  • Unity Profilerと合わせて使うことでネックを特定しやすくなったり

「データの比較」は特に便利な機能であり、例えば「最適化前の結果」と「最適化後の結果」の2点を渡すことで適用した処理の効果を簡単に比較することが出来ます。

→ e.g. とあるロジックを軽量化するとした際に、対応前のデータを事前に取っておくことで、軽量化対応後と比較してどれくらい効果があったのかを簡単にチェックする事が可能。

分析結果のフィルタリング

  • 結果を「メソッド名」や「スレッド」などでフィルタリング
    • スレッド → MainThread, RenderThread, JobWorker, etc..

例えば「レンダリング周り」で調整を入れた際には、RenderThreadでフィルタリングすることで見通しが良くなったりします。

使い方

ツールの基本的な概要及び具体的な使い方については以下の公式のブログ/ドキュメントに纏められています。

とは言え...リンクを貼って「後は読んでね」だけだと記事として微妙なので...簡単な使い方及び計測結果などを踏まえつつ解説していきます。
詳細についてはドキュメントなども合わせてご覧ください。

用語統一

Profile AnalyzerはCPUのプロファイリング結果を対象に分析を行うツールとなるので、以降の説明で出てくる「プロファイリング結果/分析結果」と言った結果を指すものについては全てCPU Profilerの結果を指します。

後はUnity Profilerでは「.data」と言う拡張子でプロファイリング結果を保存できますが、これとは別にProfile Analyzer側でも分析結果を「.pdata」と言う拡張子で保存することが出来ます。(詳細については後述)

少し用語が入り混じってくるので...以下の呼び方で統一します。

記事中での呼び方 該当箇所 拡張子
プロファイリング結果 Unity Profilerのプロファイリング結果 .data
分析結果 Profile Analyzerの分析結果 .pdata

★ 単一データの分析

サンプルとして以下のプロファイリング結果を対象に解説を進めていきます。
(物としてはNew Sceneで作ったばかりの何もないシーンで記録した300フレーム分の記録)

※ドキュメント : Single View

sample.png

Profile Analyzer側でプロファイリング結果を読み込む

次にProfile Analyzer側で結果を読み込むために先ずは画面を開きます。
Profile Analyzerはメニューバーにある「Window -> Analysis -> Profile Analyzer」から開けます。

menu.png

開くと以下の様な画面が表示されるかと思います。
後は注釈の通りに【Pull Dataボタン】を押下して先程記録(若しくはロード)したプロファイリング結果を読み込みます。

single_sample.png

※分析結果の保存について

【Pull Dataボタン】で読み込んだプロファイリング結果はProfile Analyzer側で分析された上で結果が画面に表示されます。(画面の詳細は後述)

この時の「分析結果」は【Saveボタン】から.pdataとしてファイルに保存することが出来ます。
予め分析結果を保存している場合には【Pull Dataボタン】から読み込まずとも、Profile Analyzer上の【Loadボタン】から読み込むことが出来ます。

※こちらは既知の制限としてドキュメントにも記載されており、「.dataと.pdataの両方を保持するのがオススメ」とも説明されています。

Profile Analyzerの見かた/使い方

プロファイリング結果の分析が完了すると以下の様な画面に表示が変わるかと思います。

後はこちらの画面を操作して各種分析を行う形となりますが、機能については全て解説していくと数が多いので...今回はその中にある幾つかの機能を紹介していきます。

Art004.png

複数フレームにまたがる分析

今回のプロファイリング結果は「96フレーム~396フレーム」の計300フレーム分が読み込まれてますが、この中から「110フレから140フレまでの計31フレーム分を分析したい」と言った場合には以下の注釈にある領域を操作して「複数のフレーム」を指定します。

profile_1.png

分析結果は赤枠内に表示

指定範囲の分析結果は主に赤枠内に表示されます。
例えば「Marker Details for currently selected range」の項目を見ると、マーカー名に応じた中央値(Median)平均(Mean)と言った分析結果を確認することが出来ます。

上記の31フレームの分析結果を見ると、例えば以下の要素などが確認出来ます。

Maeker Name 中央値(ms) 平均値(ms)
PlayerLoop 12.20 11.36
Camera.Render 0.15 0.17
WaitForTargetFPS 11.83 10.94

その上にある「Top 10 markers on median frame」の項目には名前の通りMedian(中央値)を基準としたTop10が表示されてます。

もちろん全範囲指定も可能

全範囲指定すれば「全フレーム分」をそのまま分析することが出来ます。
→ 選択範囲は以下の赤枠内で確認可能。

独自でツールを作ったりせずともシュッと平均値などを分析できるのは便利ですね。

profile_2.png

その他、範囲指定に関する情報はドキュメントの「Frame Control and Range Selection」を御覧ください。

項目のフィルタリング

Profilerの処理内容に該当するMakerは文字列指定やスレッド指定などでフィルタリングすることが出来ます。
指定箇所としては以下の赤枠内となります。

filter.png

名称でフィルタリング

例えば「MonoBehaviour.Update全体の負荷」を見たい場合には以下のようにUpdate.ScriptRunBehaviourUpdateを【Name Filter : All】で指定することでフィルタリング出来ます。
※今回はUpdateを呼び出す物が1つも存在しないので結果は0msとなっている。

横にある【Exclude Names】を指定すればその名称を除外することも可能です。

ScriptRunBehaviourUpdate.png

スレッド単位でフィルタリング

【Name Filter】の下にある【Thread】の項目ではThread単位でフィルタリングすることが出来ます。

デフォルトではMainThreadのみが選択されている状態となりますが、以下のようにRenderThreadのみを表示する形にして【Apply】するとRenderThreadに関する情報のみが表示されるようになります。

Art003.png

その他

詳細は割愛しますが、他にある機能として【Depth Slice】でスタックレベルでフィルタリング出来たり、【Analysis Type】で表示結果をTotal or Selfに切り替えたり出来ます。

詳細はドキュメントの「Filtering System」を御覧ください。

★ データの比較

ここからはデータの比較解説用にサンプルを変更します。

対象としては以前自分が作った「VRMSpringBoneのJobSystem対応」をベースにして、MonoBehaviourベースの実装からJobSystemベースの実装2に切り替えた際の差分に注目して解説を進めていきます。

※その他、サンプルの詳細についてはこちらを参照 (クリックで展開)
  • 検証内容
  • 実行環境
    • Standalone(Windows) + IL2CPP
    • CPU : Intel Core i7-8700K (Worker Threadは11本)

VRMSpringBoneのJobSystem対応の詳細については「こちらのスライド」を御覧ください。
ちなみに動作画面は↓になります。

aaa.png

※ドキュメント : Compare View

プロファイリング結果の読み込み

注釈の通り、読み込む必要のあるプロファイリング結果は2つ必要になります。
データが用意できたらProfile AnalyzerのModeを【Compare】に切り替えます。

データを読み込む方法については「単一データの分析」と同じです。
→ 分析データ(.pdata)が有るなら【Loadボタン】から読み込み、無ければUnity Profiler側でプロファイリング結果(.data)をロードして【Pull Dataボタン】で読み込み。

compare2.png

読み込むデータは2つ必要となるので、解説中では以下の前提で進めていきます。

  • 最適化前のデータ (MonoBehaviourベースの実装)
    • 上の青いボタンでロード
      • → 以降、画面中の青色表記は最適化前に該当
  • 最適化後のデータ (Jobsystemベースの実装)
    • 下のオレンジ色のボタンでロード
      • → 同様にオレンジ色表記は最適化後に該当

分析結果

以下に全フレーム分を対象とした分析結果を貼ります。
→ 分析方法については「単一データの分析」と変わりません。

注目できるポイントとしては赤線を引いているLateUpdateの負荷です。
VRMSpringBoneは数が多い分だけLateUpdateのMainThread占有率が目立ってしまう傾向があり、最適化後の方と比べると中央値が13.45ms削減出来ていることが分かります。

ただ、もう一点気になるポイントもあります。
箇所としては赤破線を引いているFinishFrameRenderingであり、最適化前と比べて処理が伸びていることが伺えます。
※同様に下にあるGfx.WaitForPresentなども伸びている。

springbone2.png

何故伸びた?

折角なので処理負荷の原因を特定する際の一例として伸びた原因についても簡単に追ってみたいと思います。3

今回問題となっているPostLateUpdate.FinishFrameRenderingは呼び出し階層としては結構上の方に位置しており、これだけだと具体的に「どこの処理が重いのか」が分かりづらいです。4

なので、処理を追う際にはUnity Profilerも合わせて活用する形で追っていきたいと思います。

ポイント: Unity Profilerも合わせて活用

Profile Analyzerで見れるのは「分析結果」であり、「時系列で何があったか?」と言った情報についてはUnity ProfilerのTimelineの方が確認しやすいと思います。

と言うことで2点のプロファイリング結果のTimelineを見比べてみましょう。

最適化前

(画像だけだと分かり辛いところもあるかもしれませんが...)
Profile Analyzerの分析結果と合わせてみることで以下の要点が見えてきます。

  • PostLateUpdate.FinishFrameRenderingの負荷はほぼ一律 (と言うよか目立ったスパイクとかは無い)
    • → その上でGfx.WaitForPresentは発生していない
  • Gfx.ProcessCommandsがフレーム中に完結している

def.png

最適化後

こちらもProfile Analyzerの分析結果と合わせて見ることで以下の要点が見えてきます。

  • 最適化後の方はPostLateUpdate.FinishFrameRenderingで定期的に負荷が発生
    • Timeline上のコールスタックを見るとGtx.WaitForPresentが伸びていることが見えてきた
      • ※ 同様にProfile Analyzer側でも最適化後のみGtx.WaitForPresentが伸びているのが伺える
  • 前フレームのGfx.ProcessCommandsがはみ出ている

話を纏めてしまうと最適化前と最適化後でMainThreadの処理時間が大分変わってしまっており、それが影響してGPUの実行タイミングにズレが生じてはみ出ている事が分かりました。

opt3.png

CSVへのエクスポート

分析結果はCSV形式で出力することが出来ます。

単一データの分析」又は「データの比較」で分析結果を読み込んだ状態で、メニューに有る【Exportボタン】を押下する事でメニューが表示されます。

※ドキュメント : Export Dialog

csv_ex.png

以下のCSVは、上述の「データの比較」の章にて検証した内容をそのまま出力したものです。

※画像省略 (クリックで展開)

Art001.png

まだ具体的な利用方法までは思いついていない段階ですが...自作のツールなり仕組みなりに組み込むと言ったことが可能かもしれません。

その他Tips

分析結果の表示項目の変更

以下の分析結果の表示項目について、こちらは右クリックから変更することが可能です。

  • 「単一データの分析」 → Marker Details for currently selected range
  • 「データの比較」 → Marker Comparation for currently selected range

Art001.png

項目は「単一データの分析」か「データの比較」で変わってくるので、詳細についてはドキュメントをご覧ください。

コンテキストメニューからFiltersにMarker名を追加

【Filters】への追加は直接の入力以外にも、右クリックで表示されるコンテキストメニューからも設定することが出来ます。

やり方としては「追加したいMarker名」を選択した後に右クリックで以下のようなメニューが表示されます。
→ 例えばここから「Add to Include Filter」を実行すると【Name Filter :】に選択したMarker名が追加されます。

他にも「Set as Parent Marker Filte」を実行すると【Parent Maker :】に選択したMarker名が追加され、表示内容を「指定したMarker以下のコールスタック」に限定することが出来ます。

Art002.png

その他、コンテキストメニューの内容はドキュメントを御覧ください。

最後に

まだpreview packageではありますが、触れてみて普通に使っていけそうな印象はありました。
※後は実態がEditor拡張であり、ランタイムに含まれないという点も導入しやすい感も。

解説は以上となりますが、今回話した内容以外にも色々と使い方は有るかと思います。
他に便利な使用例と言ったものが出てきたら随時アウトプットしていければと思います。
(※私以外にも「こう使ってる」「この用途だと便利」的な情報があれば、どんどんシェア/アウトプットして頂けると幸いです! :bow:)

検討事項

色々記載しましたが...言うてUnity Profilerには300フレームしか保持できない制限があります...。故に「暫く動かした結果を分析」と言った対応は難しいかもしれません。。

Unity 2019.3からは表示フレームを最大2000フレームまで引き伸ばすことが出来るので、仮にProfile Analyzerが対応されていたら活用の幅が広がるかもしれません。(まだ未検証なので要調査...)

関連リンク

Profiler基礎


  1. 実際にどれくらい使われているのだろうか..? :thinking:  

  2. 記事中ではCentralizedBufferと言う実装をベースに解説 

  3. やり方については色々とアプローチが有るかと思われます。今回は説明用の手順として考えてみた物で解説。(これが必ずしも「正しい追い方」では無いと思うのでご了承を...) 

  4. FinishFrameRenderingの下でGfx.WaitForPresentが伸びているからコレじゃね?」とパッと見て判断/自己解決できるゴリラさんなら読み飛ばしても良いかも... 

Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away