処理時間測定その4--lambdaを探せ

profilerの使い方のおさらいです   2024.0407 更新
特にprofiler hierarchy(階層)の使い方の再確認してみました
profilerを使って script1つ に相当するマーカーを探します
実験的に負荷の高いscriptを作って、問題の絞り込みを確かめてみます
◯ 今回の負荷の高いscriptは以下のとおりです。logを残すことで負荷になります
---------
$.onUpdate(deltaTime => {
let j_end = 100
for (let j = 0; j < j_end; j++) {
   $.log("無駄にlogを残す");
}
});
-----------
発見しやすいように負荷を誇張しています。100回ループぐらいで1F=60msぐらいの負荷になりました
今回は、10回ループのscriptの付いたitemを10個複製して100回分の負荷としました
まず deep profile modeで測定します。適当な時刻を選択します。
profiler timeline は直感的に洞察するのによいですね、末端が10個に割れているのが見えます。
scriptが 10個複製 されたことに対応していることが視覚的に見えます

◯ マーカーって何?
profiler timeline で横長のブロックがDocumentでいうところのマーカーのようです
でかいマーカーを探せば負荷の原因を探しやすいという理屈です
しかしマーカーが小さく 多数に散らばっているなら とても探しきれません
マーカーのtimelineでの様子は壮大で複雑で精密でケース・バイ・ケースで 様変わりします
この横文字のゴチャゴチャに深入りしたくないものです
◯ そこで  Profilerのhierarchy(階層)の検索機能を使います
目的のマーカーのスペルまで わかっていれば 階層で検索すると手っ取り早いでしょう
しかし、当てずっぽうの推理で検索を繰り返すのも不毛です
(偶然ヒットすることもありますが安定したやり方ともおもえません)
そこで、ずばりのマーカー名がわからなくても 着目するとよいマーカー名のリストがあれば
そのキーワード候補で検索して その上下近くを探すと段取りがよいように思います
現時点の有力候補は [lambda]ですが 別の目的で別のマーカーを探す場合に備えて
profilerの使い方をおさらいしていきます

◯ もしマーカー候補がまったくわからない状態から探すなら
▼マークを闇雲にポチポチ開いて探すことになり無数のマーカーと深い階層に出くわします
あるいは▼マークをALTキーを押しながらclickすると全ての階層が末端まで展開することができます。
やはり無数のマーカーと深い階層に出くわします
◯ では、検索機能をつかってみましょう
キーワードとして[KaomoLab]の文字で検索してみます script関係を絞り込めて手っ取り早いです
先頭文字がKaomoLab~~のマーカーがヒットするはずです
後述しますが階層表示でないと素直にソート操作が使えます
◯ 検索でうまくヒットしない場合の注意点が2つ
1. DeepProfileモードで測定したかどうか点検します
2. フルネーム(show full scripting Method Names )表示になっているか点検します
( runner  lambdaは deep測定でないとヒットしない)
  フルネームでないとKaomoLab~~がヒットしない  

◯ Profilerのhierarchy(階層)の検索に文字を入れると
階層という名前なのに[階層]でない一覧表示になるようです
▼マークが見当たらないことで区別ができます
アルファベット順にしたり降順・昇順にしたりソート操作が素直に使えます

◯ 処理時間も加味して絞り込みましょう。今回はそのために処理時間を誇張しています
ミリ秒=msが大きいものから下へたどります
(total %に着目するのもありですね 負荷に対する%表示の方がわかりやすいかもしれません)
小さい▼のあるところが ソート項目で defaultは Time ms のようです
 図参照

◯ 先頭文字ではなく末端文字に着目します
先頭文字がライブラリ名とか大きな分類のようです
末端文字がなにやら具体的な内容に近いヒントになっているのでしょうか
キーワード候補の[KaomoLab~~CodeRunner] が見つかりました calls数10 ですから scriptの数を反映しています
「script1つ に相当するマーカー」 の候補がみつかりました。それだけではなく
「コマンド1つに相当するマーカー」 が見つけられました
深くたどると Log~何とか~というMarkerがいくつか見つかります
例えば[KaomoLab~~DebugLogger.Info]に着目すると
100回callしたという数値もあるので これが $.log コマンドひとつに相当すると思われます
飽くまで 憶測です。(立証する必要もないと思います 飽くまで作業上の仮定でいいと思います)
このようにどのMarkerに着目すればよいか 候補がいくつか見つかります
◯ このままでは[KaomoLab]しばりで、偏っています。
それ以外のマーカーにも捜索範囲を広げたいと思います
検索項目を空欄に戻します。▼マークを使った 階層表現に戻りますが
特定のマーカーを選択していれば そこに着目して階層を展開した状態になるようです
今回は [CodeRunner] や [DebugLogger.Info] を選択しておきます

◯ 所属関係が見やすい階層表示にして観察してみます
(見つけたMarkerを選択しておかないと▼マークをいちいち開いて探すはめになります)
どういうわけかきれいな階段状に並んでいます。条件によっては違うのでしょうか
これが正しい使い方のような気がします。
ここで下手に降順を昇順に変えるとわけのわからない並び順になります
階層が絡んでいるからでしょう。どういうルールか解説してほしいです。
ただし、選択したマーカーは見失ってはいないようです。
エレベータを動かして探すと見つかります。
◯ それと、profilerの階層の折りたたみと展開はどういうルールになっているのでしょうか
階層を折りたたんでも  CPUUsageをClickまたはスクラブルすると階層が展開します
あくまで選択したマーカーを基準に開くようです
測定をclearしても 直前に使っていたマーカーを覚えているようです
これは便利そうです(文献上の根拠はありません 発見したTipsです)
◯ 検索項目が空欄なら ▼マークのある階層表示になっているはずです これをじっくり観察します
かおもさんのエミュレーターが機能するのにいろんなライブラリが
後になったり先になったり 入り組んで 処理をしているようです
    UnityEngine.UI.dll!
    ClusterVR.CreatorKit.Preview.dll!
    mscorlib.dll!
    Jint.dll!
・・・などが見受けられます
横文字アルファベットのゴチャゴチャに深入りしたくなかったのですが
正常な状態を観察しておくことは
いざというデバグや負荷対策の時に役立つでしょうか
◯ この状態を画像ではなくテキストでコピーして記録したり整理したい場合は
profiler timelineの黒字に白のフキダシから show>selected Sample Stack でcopyできます

◯ 「scriptひとつに相当しそうなマーカー」の候補がさらに増えました
実験の詳細は省きますが
onUpdate、onInteract、onCollision、onGrab、onUse でいくつか調べたところ
[CodeRunner]は共通ではありませんでした
発見したのは [mscorlib.dll!System::Object.lambda_method()] です
これが共通して存在していました
理論的根拠に乏しいですが lambdaは 覚えやすいので お勧めかもしれません 
「lambda」の読み方は? ギリシャ文字「Λ (ラムダ)」です 
このようにケースバイケースで 目的とするマーカーを絞り込めるでしょう
◯ 環境その他
無謀にもprofiler学習直後の勢いでprofilerの使い方を自分用に書いています
参考になれば幸いですが 検証できていない 憶測も含みます
参考にする方は自己責任でお願いします
#cluster #ClusterScript
環境 Unity 2021.3  CCK2.9.0      かおもさんのエミュレータ(CSEmulator2.22)  
Profile Analyzer 1.1.1 cluster v2.116(2024/03/18)
謝辞    ヒントをくれたかおもさんに感謝