もっと正しいやり方があるかもしれません
optionや使い方が他にもあって 検証していないので
誰か正しい記事を書いてね
◯ マーカーって何?
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] を選択しておきます
手順E DeepProfileオンの場合----------------------------------
手順AにDeepProfileオンを加味します 前回の手順Aを参照のこと
今回の実験データはscript付きitemを20数個に複製し
script負荷を強調したものです
省略されていたブロックも全部表示されるらしく 印象が変わります
測定前にオンにしないと効果がないようです
画面では Deep profile mode の灰色がオンかオフか見分けにくいですね
Timelineの階層が増えて さらに複雑になっています
見慣れないアルファベットがびっしりで拒否反応が起きるところです
ここまで深入りしたくなかったというヒトもいるでしょう
ヒントの [EngineFacade.Update]のブロックを探します
timelineでは 探しにくいので
Profilerのhierarchy(階層)で検索します
ちなみにDeepProfileオフで測定してもヒットしません。
スペルミス に注意ですね(大文字・小文字の区別はないようです)
[KaomoLab]で検索するのもいいでしょう script関係がヒットします
(KaomoLab~~が たぶんscript関係でしょう 検証しきれていませんが)
ミリ秒順にソートされているらしく 処理時間の長いものが先頭にあります
今回は[EngineFacade.Update] をピンポイントで探せばよい
・・・という目処があるので心強いです
図のミリ秒を見ると 処理時間 51.88msとか
1フレーム63.92msに近い値です ぴったり一致はしてませんが
処理負荷の主な原因を表しているようです
今回の実験データではscript付きitemを20数個に複製し
script負荷を強調したものです
No Details を Related data にすると内訳が表示されます
(選択しておかないと何も見えません)20数個ならんでいます
なるほど [CodeRunner.Update] は jsファイル1個分のようです
ひとつのscriptの処理時間が約2msであることも表示されています
この値が信用できるかどうか 後で検討します
自分の作ったscript名がそのままマーカー名とか
ブロック名として登場はしないようです
慣れてくれば timelineよりは hierarchy(階層)の方が使い良いのでしょう
念のため、これを timelineで視覚的に確認してみます
hierarchy(階層)で選択してあれば 黒地に白文字の吹き出しが 表示されています
ショートカット[F]やホイールボタンや
下段のエレベータを駆使して見え方をスケールします
図では[EngineFacade.Update]の長いブロックの下に
[CodeRunner.Update]が20数個ぶらさがっている様子が見えます
これで、
「 EngineFacade.Update が1フレームのscriptの総計らしい
CodeRunner.Update がscript1個分であるらしい」
・・・ということを確認しました。めでたしめでたし
補足---------------
◯ 右肩の点3つメニューに show full scripting Method Names のoptionがあります
これだと先頭にKaomoとついているものがscriptがらみとして探しやすいです
慣れてくると短いほうが [CodeRunner.Update]を 探しやすいかもしれません
◯ Deep profile mode でフリーズの危険性
Script付きザリガニ50匹の重いシーンデータを測定できたのですが
analyzeしようと load dataしたら フリーズしました 10分待っっても終了しません
Deep profile + analyze の組み合わせは危険です
文献によると
「ディーププロファイリングはリソースを大量に消費し、多くのメモリを使用します。
ディーププロファイリングは、簡単なスクリプトで動く小さなゲームに適しています。
複雑なスクリプトコードを使用している場合、
アプリケーションでディーププロファイリングをまったく使用できない場合があります。」
・・・なるほどdefaultでオンになっていなかった理由があるのですね 一長一短があります
◯ Scriptの処理時間がそのまま信用できるかどうか
Deep profile モードでは profiler自体の負荷が影響して
ほぼ同じ条件でも1フレームの測定値が異なりました
実験データでは 5倍も違いました
DeepProfile オフ 1フレーム=12ms
DeepProfile オン 1フレーム=63ms
この状態で測定されたscript1つの処理時間をそのまま信用できるのでしょうか
何分の1か比率を掛けて補正すればよいのでしょうか
Profilerは飽くまで 負荷原因を絞り込むツールであって・・・・
数値をよそに持ちだせるほど 本番に近い測定ツールでしょうか
◯ 手順Eが当てはまらない場合
scriptの本文が OnUPdateなら当てはまることが
scriptの本文が OnInteractなら その手順が当てはまらないようです
例えば 前前回の負荷測定用データ test_ms_009B.unity は Interact タイプなので
[EngineFacade.Update]や[CodeRunner.Update]が小さすぎて
1フレームの負荷を反映していませんでした
そこで [KaomoLab]で検索したところ
[InteractItemTrigger_TriggerEven] に着目したほうがよいみたいだと思われます
時間切れで 検証しきれていません。
・・・・・以上追記しておきます
飽くまで体験記です。
検証できていない 憶測も含みます 参考にする方は自己責任でお願いします
#cluster #ClusterScript
x
作ったscriptが重いかどうか知りたいだけだった
・・・なのに深みにはまってしまいました
誰かが正しい解説記事を書いてくれると期待して体験記を書きます
読者対象は中級者向けのCluster記事を書けそうな人です
2024.0328 更新
目次----------------
記事の目的
信頼できるミリ秒を探し求めた経緯
時間についてのエッセイ
Unity profiler お勧め手順案A
その他の手順と疑問点
参考文献
環境その他
記事の目的 ---------------
作ったscriptの処理時間を知るためにUnity profiler を再勉強してみました
Unity profiler の一般の記事は ありますが 難しく奥が深く発展途上のようです
さらに Cluster CCK で成立するのかという 条件付きで学習せざるを得ません
どこかに不具合やちょっとしたバグがあれば なおさらつまづきます
そこで 条件として
CCK + かおもさんのエミュレーター + Unity profiler
の環境で解説記事がほしいです
問題提起をかねて体験記を書いてみます
信頼できるミリ秒を探し求めた経緯-------------------------------------------
処理負荷をどれで判断するか深入りした経過です
簡単なものから難しいものの順で述べます
1. Cluster本番の 統計 ------------------v
Clusterのワールドに入った時の右上に表示される統計です
他人のワールドも測定できます ms=ミリ秒があります
FPS:(CPU ms Render ms)
リアルタイムで数値が変化するので最初のうちは頼りにしていました
アバターの見る風景を動かす・・つまりカメラを動かすと
即刻にrenderのミリ秒が変化して わかりやすかったです
重たいバーカウンタや鏡や多数のアバターに視線を向けると
グラフィックの処理負荷が重くなるのがわかります
しかし、script負荷や厳密な分析や比較には不便を感じます
数値が刻々と変化するのでどの値を記録すればいいのでしょう
VRの場合はsteamの ミリ秒表示を使う手もあります
Clusterの値とは同じではないようです
2. Cluster本番の Consoleのエラーと警告------------^
ワールド制作者にしか見えないアレです
処理時間に関する警告が出ることがあります
WARN: script execution (383ms) exceeded the soft limit (50ms).
Scriptに関するエラーもあります
Script has allocated too much memory
これが不便であるということは別記事に書きました
3. UnityのPlay Gameの statistics (統計表示) ------------
このなかで SetPass calls の値は グラフィック負荷の判断に使えました
しかし、処理時間を表すミリ秒は不安定でコロコロ変わりすぎます
しかも3種類あります
FPS( ms) CPU:main msの値 render Thread msと
これらは何を意味しているのでしょうか
簡易的に瞬間的な変動を知るぐらいにしか役立たないように思います
目視で平均値を推定して記録しようとしても
script負荷や厳密な分析や比較には不便を感じます
この手順に間違いない・・・と思いたいわけです。
なので他の手順も調べます
手順案D [ EditMode + Play ] の場合 -------------------v
EditMode で PlayGameすると 別の測定結果がでます
かおもさんのエミュレーターの FPS制限90FPS設定が効いてないようです
TimeLineの構造がシンプルなので何かに使えそうです どなたか解説してほしいです
◯ 考察・・・たまに変な値になるし、文献にもないし よくわかりません
もしも、かおもさんのエミュレータがなければ
unity editor上で profiler分析ができません
するとこんな手探りしかできないのではないでしょうか
負荷を変えて測定して 10回づつ測定しました
scriptが最終行まで実行されたら◯
errorが出たらxとしました
数字は scriptが処理にかかった時間です
負荷が小さく16ms以内ならリニアな関係だろうと予想できます
負荷が大きくなれば16msを境に x ばかりと予想しましたが
測定では 負荷が大きくなると 結果がばらついて
ラチがあきません 再現性がなさすぎます
この赤!マークのエラー を考察してみます
[Script has allocated too much memory]
直訳では「メモリーをたくさん喰っています」という文ですが
いままでも 入室の最初に見かけることが多く 実態に合わない的外れなエラーという印象でした
おそらく言葉どおりの意味ではなく 出現するタイミングから 黄色警告と同じような
「処理時間が長いよ」という意味に解釈したほうがいいように思います
あるいは 分類不能なエラーは何でもこれに紐づけしているのかもしれません
そういえば Unity profilerで観察しているとplay game直後に スパイクが生じがちなので
結局 スパイクを表現しようとしていると勝手に解釈しています
(個人の見解です。検証実験や文献上の根拠はありません)
この黄色の警告を考察してみます
> WARN: script execution (383ms) exceeded the soft limit (50ms).
1つのscriptの処理時間ではなく 複数のスクリプトの合計
たぶん ワールド全体の処理時間を意味しているようです
だとすると どのスクリプトの何行目なのかという 情報は期待できないかもしれません
未解決なことが多々あります
soft limit (50ms) hard limit (500ms)の意味が不明です
ソフトウエア上の制限とハードウエア上の制限でしょうか
単にゆるい制限ときつい制限という意味でしょうか
「将来的に施行される予定」とか 500msに緩和されたとか
よくわからないことが多々ありますが 報告を一旦ここまでとします
考察はいくつかの実験から仮説を立てたもので 文献上の裏付けがありませんので誤解なきように
提案------------------
ここでさらに稚拙な提案をしておきます
別の開発環境ではlua言語で nilトラップ というテクニックがありました
「ユーザーの作ったscriptを中断するならば
処理時間が制限を超えた時に何らかの信号を出して
ユーザーがそれにトラップをかけて
対策処理を書けるようにしたらどうでしょうか」
処理時間を短くしろという警告だけでは工夫が足りないように思います
・・以上 測定の体験と考察と提案です
なお専門家ではないので理解に間違いがあればお許しください
環境 CCK2.8.0 かおもさんのエミュレータ(CSEmulator2.20)
測定用の scriptとuntityデータを置きました
https://drive.google.com/file/d/1pnkYNNRRa1jhXuPtkqwuxpBgsYMdiGAX/view?usp=sharing
test_ms_009.unitypackage
test_ms_009_readme.txt
この2つを含む zipファイルです
#cluster #ClusterScript
例えば・・・・・
このときにメモったTipsを書いておきましょう