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

この記事は[【unityプロ技②】 Advent Calendar 2019](https://qiita.com/advent-calendar/2019/unityforpro2)の7日目の記事です。

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

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

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


## 検証環境

### Unity version

- Unity 2018.4.13f1+
    - ※[Documents](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@latest/index.html)曰く**「Unity5.6以降」** までは互換性があるとのこと。(PackageManagerの管理下よりコピーしてくれば動作するらしい？）

### Packages version

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

## ※注意点

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

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

- [一歩先のUnityでのパフォーマンス/メモリ計測、デバッグ術](https://learning.unity3d.jp/1365/)
- [Unity2018/2019における最適化事情](https://learning.unity3d.jp/3943/)
    - 比較的新しい資料。Profilerに関する最新機能などについても言及されている
- [【Unity道場スペシャル 2017京都】最適化をする前に覚えておきたい技術](https://www.slideshare.net/UnityTechnologiesJapan/unity-2017-82248953)
    - [講演動画はこちら](https://www.youtube.com/watch?v=MfbZ_jZ9G9I)
    - `Unity Profiler`に関して凄く分かりやすく解説されている
    - 数年前の資料故に最新機能などは言及されていないので、上記2点と合わせてみることで補完できるかも





# TL;DR

## このツールは何？

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

## ツールで出来ること

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

### ★ 単一データの分析

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

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


### ★ データの比較

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

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

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


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

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

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










# 使い方

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

- **[Profile Analyzer のご紹介](https://blogs.unity3d.com/jp/2019/05/13/introducing-the-profile-analyzer/)**
- **[About Profile Analyzer (Documents)](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@latest/index.html)**

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



### 用語統一

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

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

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

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



## ★ 単一データの分析

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

※ドキュメント : [Single View](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/single-view.html)

![sample.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/17a72d7d-861a-1616-440e-237c3acebad7.png)


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

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

![menu.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/7079b064-0717-a665-cfcf-3ad712989ffb.png)


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

![single_sample.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/400d748d-be58-8dcd-3644-55bc5642cc8f.png)

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

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

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

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



### `Profile Analyzer`の見かた/使い方

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

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

![Art004.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/505d5204-6c10-da2a-3302-024621a9dc9d.png)


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

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

![profile_1.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/0e2ca087-b995-18d3-1897-ee88f35bba6b.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](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/49ba12ea-62d3-56cf-fd39-47e085c66a56.png)

その他、範囲指定に関する情報はドキュメントの「[Frame Control and Range Selection](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/frame-range-selection.html)」を御覧ください。



#### 項目のフィルタリング

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

![filter.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/0d5585d1-afb6-161e-a925-3b8e43e27c25.png)

##### 名称でフィルタリング

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

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

![ScriptRunBehaviourUpdate.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/342b95a6-21c5-5a19-d743-0100a02a640e.png)


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

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

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


![Art003.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/13dbf2b2-993e-1d6b-f462-3c76618f1687.png)


##### その他

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

詳細はドキュメントの「[Filtering System](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/filtering-system.html)」を御覧ください。










## ★ データの比較

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

対象としては以前自分が作った「[VRMSpringBoneのJobSystem対応](https://github.com/mao-test-h/VRMSpringBone-Optimize)」をベースにして、`MonoBehaviourベースの実装`から`JobSystemベースの実装`[^2]に切り替えた際の差分に注目して解説を進めていきます。

[^2]: 記事中では`CentralizedBuffer`と言う実装をベースに解説

<details><summary>※その他、サンプルの詳細についてはこちらを参照 (クリックで展開)</summary><div>

- **検証内容**
    - 「[ニコニ立体ちゃん VRMモデル](https://3d.nicovideo.jp/works/td32797)」256体を同時に動かした際の`VRMSpringBone`の処理負荷軽減
- **実行環境**
    - Standalone(Windows) + IL2CPP
    - CPU : Intel Core i7-8700K (Worker Threadは11本)

`VRMSpringBone`のJobSystem対応の詳細については「[こちらのスライド](https://speakerdeck.com/mao_test_h/vrmspringbonewojobsystem-and-ecsdezui-shi-hua-sitemitahua)」を御覧ください。
ちなみに動作画面は↓になります。

![aaa.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/0e935de3-278d-6748-e6f2-ecd64cab8181.png)

</div></details>

※ドキュメント : [Compare View](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/compare-view.html)



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

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

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


![compare2.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/a15ee7b7-f9b3-7322-4bb9-4e7da9642f62.png)


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

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



### 分析結果

以下に**全フレーム分を対象とした分析結果**を貼ります。
→ 分析方法については「[単一データの分析](https://qiita.com/mao_/private/f8e61bf1d9d5aa5d7fe4#-%E5%8D%98%E4%B8%80%E3%83%87%E3%83%BC%E3%82%BF%E3%81%AE%E5%88%86%E6%9E%90-1)」と変わりません。

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

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

![springbone2.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/30f65491-55c4-1f89-94df-62e344b1d62f.png)



#### 何故伸びた？

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

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

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

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

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


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

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


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

##### 最適化前

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

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

![def.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/b27a44ac-d56b-5f5c-3696-7bf38ad1137c.png)


##### 最適化後

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

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

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

![opt3.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/cfde6761-ef7b-7cff-31b7-f00eb55ed4c3.png)









## CSVへのエクスポート

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

「[単一データの分析](https://qiita.com/mao_/private/f8e61bf1d9d5aa5d7fe4#-%E5%8D%98%E4%B8%80%E3%83%87%E3%83%BC%E3%82%BF%E3%81%AE%E5%88%86%E6%9E%90-1)」又は「[データの比較](https://qiita.com/mao_/private/f8e61bf1d9d5aa5d7fe4#-%E3%83%87%E3%83%BC%E3%82%BF%E3%81%AE%E6%AF%94%E8%BC%83-1)」で分析結果を読み込んだ状態で、メニューに有る【Exportボタン】を押下する事でメニューが表示されます。

※ドキュメント : [Export Dialog](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/export-dialog.html)

![csv_ex.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/ae4305c3-d85f-d8cf-474a-4f1dea254e74.png)

以下の`CSV`は、上述の「[データの比較](https://qiita.com/mao_/private/f8e61bf1d9d5aa5d7fe4#-%E3%83%87%E3%83%BC%E3%82%BF%E3%81%AE%E6%AF%94%E8%BC%83-1)」の章にて検証した内容をそのまま出力したものです。

<details><summary>※画像省略 (クリックで展開)</summary><div>

![Art001.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/1603fff7-bf72-4e16-f66c-85cc5c1ca033.png)

</div></details>

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





## その他Tips

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

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

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

![Art001.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/81438cbd-9eb2-063a-1aa4-a1057ddaa884.png)

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

- [Single View](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/single-view.html)
- [Compare View](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/compare-view.html)


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

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

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

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

![Art002.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/80207/5fdbd8c5-1c28-6afc-ab81-1f0f028e8790.png)

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

- [Marker List Context Menu Commands](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@0.5/manual/single-view.html)





# 最後に

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

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


### 検討事項

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

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







# 関連リンク

- [About Profile Analyzer(Documents)](https://docs.unity3d.com/Packages/com.unity.performance.profile-analyzer@latest/index.html)
- [Profile Analyzer のご紹介](https://blogs.unity3d.com/jp/2019/05/13/introducing-the-profile-analyzer/)
    - 公式ブログ記事。和訳されている

## Profiler基礎

- [一歩先のUnityでのパフォーマンス/メモリ計測、デバッグ術](https://learning.unity3d.jp/1365/)
- [Unity2018/2019における最適化事情](https://learning.unity3d.jp/3943/)
- [【Unity道場スペシャル 2017京都】最適化をする前に覚えておきたい技術](https://www.slideshare.net/UnityTechnologiesJapan/unity-2017-82248953)
    - [※講演動画はこちら](https://www.youtube.com/watch?v=MfbZ_jZ9G9I)