ぱぴブログ

さんたろのブログ

ゲーム開発が好きな人のひとりごと

Unityで特定の処理を分析したい ~Unity Profile Analyzer~


はじめに

みなさんこんにちは。さんたろです。

本記事はUnityゲーム開発者ギルドAdvent Calendar 2020の19日目の記事です。

adventar.org

開発環境

Windows 10
・Unity2018.4.14f1

きっかけ

「特定の処理にかかった時間やGCAllocを計測したい」というときがあると思います。
かかった時間だけならStopWatch()を利用することで計測できます(多少の誤差は出ますが)。

public class SampleClass : MonoBehaviour
{
    [SerializeField] private GameObject sampleObj;

    private void Update()
    {
        if (Input.GetKeyDown(KeyCode.Return))
        {
            HeavyFunc();
        }
    }

    private void HeavyFunc()
    {
        var sw = new System.Diagnostics.Stopwatch();
        sw.Start();
        for (int i = 0; i < 10000; i++)
        {
            sampleObj.SetActive(false);
            sampleObj.SetActive(true);
        }
        sw.Stop();
        Debug.Log(sw.Elapsed);
    }
}

上のクラスを実行すると、Enterキーが押されるたびにHeavyFunc()が実行されます。
1回の実行で0.01秒以上かかっていることがわかりますね(10万回にすればよかった)。

f:id:papyrustaro:20201219143402p:plain
StopWatchの出力

もう少し詳しい情報が欲しい、というときに最初に挙げられるのはUnityのProfilerだと思います。

1.Profilerを使ってみる

UnityのProfilerを使用してみます。
Unityエディタ上で[Window]->[Analysis]->[Profiler]から開くことができます。

docs.unity3d.com

この記事ではProfilerの使い方について特に記述しません。
Unity公式リファレンスや他の方の記事を参考にしてください。

CustomSamplerクラスを利用してHeavyFunc()を"HeavyFunc"という名前をつけてProfilerに表示させます。

using UnityEngine.Profiling;
~~~~~~~~~~~~~~~~~~~~~~~~~~

private void HeavyFunc()
{
    var sampler = CustomSampler.Create("HeavyFunc");
    sampler.Begin();
    for (int i = 0; i < 10000; i++)
    {
        sampleObj.SetActive(false);
        sampleObj.SetActive(true);
    }
    sampler.End();
}

1.CPU UsageとTimeline

実行して何度かEnterを押してProfilerウィンドウで見てみます。

f:id:papyrustaro:20201219143754p:plain
Profilerウィンドウ

「CPU Usage」を見ると、明らかに飛び出ている部分がありますね。
飛び出ている部分をクリックすると、下のTimelineにそのフレーム周りの処理の流れが表示されます。
「HeavyFunc」という名前で水色で書かれていますね。16.83ms処理に時間がかかっていることがわかります。
ここで表示される「HeavyFunc」とはCustomSamplerで設定した名前です。

1.Hierarchy

では、CPU UsageでHeavyFuncが呼ばれているフレームを選択したまま、TimelineからHierarchyウィンドウに変えてみましょう。
そうすると、HeavyFuncが呼ばれている選択したフレームにおける、各処理ごとの詳細が一覧で映ります。

f:id:papyrustaro:20201219144806p:plain
Hierarchyウィンドウ

次に、Hierarchyウィンドウの右上の検索から「HeavyFunc」と検索するとそのフレームでのHeavyFuncの処理について出てきます。
ちなみにHierarchyウィンドウ上のHeavyFuncをクリックしてから検索の×ボタンを押すと、全体の処理から「HeavyFunc」までの処理の階層がわかります。

f:id:papyrustaro:20201219145045p:plain
Hierarchyで「HeavyFunc」を検索

f:id:papyrustaro:20201219145336p:plain
HeavyFuncまでの階層

1.Profilerの問題点

Profilerは「指定されたフレームの処理」での特定の処理の検索はできますが、「複数フレームにまたがった」検索ができません(調べた範囲では)。
今回は明らかに呼ばれたタイミングが「CPU Usage」からわかりますが、毎回そう見やすい反応になるわけではありません(他の処理が多い、計測したい処理が極端に重くない)。
また、「どのくらいの頻度で呼ばれているのか」「複数回処理のパフォーマンスの平均」などはわかりにくいです。

2.Profile Analyzer

「Profile Analyzer」というものが便利という話を聞き試してみることにしました。

forpro.unity3d.jp

blogs.unity3d.com

機能や基本的な使い方に関しては、以下の記事でわかりやすくまとめられています。

qiita.com

2.導入方法

Unityエディタで[Window]->[Package Manager]にて、「Profile Analyzer」と検索して出てきたものを選択し、Installを押せば利用できます。
検索しても出てこない場合は、検索欄の左にある「Advanced」から「Show preview packages」にチェックを入れると解決するかもしれません。

2.使ってみる

「Profile Analyzer」はProfilerで計測した情報をもとに、より便利な解析を可能にします。
今回は先ほど計測した、何度かHeavyFuncを呼んだものを利用します。

Profile Analyzerのウィンドウを開き、「Pull Data」を押すことで現在のProfilerのデータを読み込みます。

f:id:papyrustaro:20201219151700p:plain
Pull Dataボタンで読み込む

読み込むと、明らかに緑のバーが突き抜けている個所がいくつかありますね。ここでHeavyFuncが呼ばれています。

実際に検索してみましょう。FiltersのName Filterを「HeavyFunc」とします。
そして上のグラフの検索範囲フレームをドラッグでてきとうに指定します。
以下が検索結果です。

f:id:papyrustaro:20201219152736p:plain
Profile Analyzer 検索結果

正直このスクショだけでどれだけ便利なのかわかると思います。
HeavyFuncが呼ばれてるフレーム、各処理時間やその平均、最大処理時間など一目でわかります。
呼ばれているフレームがわかれば、ProfilerのHierarchyから詳細情報を確認することも容易です。

今回は紹介しませんが、ふたつのプロファイリングの結果を比較したり、csvファイルに出力することなどもできます。

単純に今までのProfilerの拡張機能として利用していけそうです。

さいごに

Profile Analyzerとっても便利なのに、全然推されていないですね。なにかわけが...??

なぜこの記事をUnityゲーム開発者ギルド(UGDG)のアドカレにしたかというと、Profilerの扱いに困っていたときにこのギルドで質問してギルドメンバーの方がProfiler Analyzerを紹介してくださったからです。

UGDGに所属したのは今年の7月と、まだ5か月ほどしか経っていませんがSlackを中心とした交流はとても楽しいです。
もちろん技術的な質問もできますが、分報チャンネルで今日の出来事を呟いたり、一緒にゲームしたり、配信したり、ひとつのテーマで何か作ってみたり、と本当にいろいろとおこなわれていて最高です!!!

UGDGはいいぞ