Unreal Engine 4 (UE4) Advent Calendar 2018の12月10日の記事です。
- [UE4]InstancedStaticMeshのInstanceIDを何とかしてマテリアルで取得する
- [UE4]GarbageCollectの対象周りを調べてみた
UE4.21.1で検証
→UE4.25でUPropery系がUObjectから外された影響でこの記事の話は無くなりそうです
#UE4.25 UObjectの数。
— com04 (@com04) March 7, 2020
4.24で作ったThirdPersonプロジェクトをパッケージ化。
→4.25 preview1にバージョン変更してパッケージ化。
で見てみた。
UObjectが30,000くらい減ってる。Property系が消滅している模様 pic.twitter.com/z4D9Si5Qvr
ログの表示
コンソールコマンド
log LogGarbage Verbose
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 25.012325 ms for Mark Phase (44975 Objects To Serialize
LogGarbage: Verbose: 4.298625 ms for Reachability Analysis
LogGarbage: 29.482862 ms for GC
LogGarbage: 0.056010 ms for Gather Unreachable Objects (5 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.023569 ms for unhashing unreachable objects. Items 5 (5/5)
LogGarbage: GC purged 5 objects (47621 -> 47616)
obj list
Class Count NumKB MaxKB ResExcKB ResExcDedSysKB ResExcShrSysKB ResExcDedVidKB ResExcShrVidKB ResExcUnkKB
Class 1720 1115.12 1277.75 0.00 0.00 0.00 0.00 0.00 0.00
Function 4560 932.32 1046.28 0.00 0.00 0.00 0.00 0.00 0.00
StructProperty 5735 716.88 716.88 0.00 0.00 0.00 0.00 0.00 0.00
BoolProperty 4384 548.00 548.00 0.00 0.00 0.00 0.00 0.00 0.00
FloatProperty 3674 430.55 430.55 0.00 0.00 0.00 0.00 0.00 0.00
ObjectProperty 2819 352.38 352.38 0.00 0.00 0.00 0.00 0.00 0.00
ScriptStruct 1277 241.05 296.38 0.00 0.00 0.00 0.00 0.00 0.00
33160 Objects (Total: 6.478M / Max: 6.955M / Res: 34.187M | ResDedSys: 1.233M / ResShrSys: 0.000M / ResDedVid: 32.936M / ResShrVid: 0.000M / ResUnknown: 0.018M)
UObjectの数を表示できる。=GC対象
ゲームプレイしていると、やたらGC削除対象が多い……
とか思った時に、然るべきタイミングでの差分を見て何が増えたのか調べたり。
Blueprint Stats Plugin
DumpBlueprintStats
が使えるようになる
(ただパッケージ版で使えなかったり、BP指定して個別のstats取れないの使いにくくない……?まだExperimentalっぽい?
BP指定してその1つのBPでのstats取れるように拡張すると便利そう)
Cmd: DumpBlueprintStats
LogBlueprintStats: Blueprint stats for 19 blueprints in TestGC
LogBlueprintStats: Total,DOBP,NumNodes,ImpureWI,ImpureWO,ImpureWIO,ImpureTotal,PureTotal,UserFnCount,UserPureCount,UserMacroCount
LogBlueprintStats: 19,6,1088,81,14,10,84,416,19,1,30
どれが幾つ有るか
LogBlueprintStats: NodeClass,NumInstances
LogBlueprintStats: K2Node_CallFunction,310
LogBlueprintStats: K2Node_CommutativeAssociativeBinaryOperator,154
LogBlueprintStats: K2Node_VariableGet,112
LogBlueprintStats: EdGraphNode_Comment,63
各ノードのインスタンスが幾つ有るか
LogBlueprintStats: FunctionPath,ClassName,FunctionName,NumInstances
LogBlueprintStats: /Script/Engine.KismetStringLibrary:Concat_StrStr,KismetStringLibrary,Concat_StrStr,127
LogBlueprintStats: /Script/Engine.KismetStringLibrary:BuildString_Int,KismetStringLibrary,BuildString_Int,25
LogBlueprintStats: /Script/Engine.KismetTextLibrary:Conv_FloatToText,KismetTextLibrary,Conv_FloatToText,19
LogBlueprintStats: /Script/Engine.KismetTextLibrary:Conv_TextToString,KismetTextLibrary,Conv_TextToString,19
各関数のインスタンスが幾つ有るか
参考
- [4.20版] UE4におけるLoadingとGCのProfilingと最適化手法
https://www.slideshare.net/EpicGamesJapan/420-ue4loadinggcprofiling-108367408
検証してみた
- gc.MaxObjectsNotConsideredByGC
LogUObjectArray: 34975 objects as part of root set at end of initial load.
LogUObjectArray: 2 objects are not in the root set, but can never be destroyed because they are in the DisregardForGC set.
LogUObjectAllocator: 5223472 out of 0 bytes used by permanent object pool.
LogUObjectArray: CloseDisregardForGC: 34975/34975 objects in disregard for GC pool
数値取ったけど、以後のパターンどれでも数値は変わらず。
- GCログ
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.009153 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004157 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (169 -> 169)
// Spawn後
LogBlueprintUserMessages: [NewMap_C_2] Spawn
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.009984 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004161 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (171 -> 171)
// Destroy後
LogBlueprintUserMessages: [NewMap_C_2] Destroy
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006378 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004437 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.011645 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (171 -> 169)
Spawn前のGC対象のオブジェクトは169。
Spawnした後のGC対象のオブジェクトは171。空BPでオブジェクトが2つ増えた。
DestroyでGCに2個持っていかれた
ちなみに、2回Spawnしても173になるだけ。
- obj listの差分
// Spawn前
SceneComponent 6
// Spawn中
SceneComponent 7
BP_Test_C 1
GCに持っていかれたのはこの2つ
SpawnするBPに変数増やしてみた
- GCログ
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006378 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004157 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (175 -> 175)
// Spawn後
LogBlueprintUserMessages: [NewMap_C_2] Spawn
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006933 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004437 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (177 -> 177)
// Destroy後
LogBlueprintUserMessages: [NewMap_C_2] Destroy
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006657 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004437 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.011645 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (177 -> 175)
Spawn前のGC対象のオブジェクトが169から175に増えた
Spawnした後のGC対象のオブジェクトは177。増える量は2で変わらない
- 増えた6個分のGC対象
// 空のBP
Function 4556
StructProperty 5732
BoolProperty 4383
FloatProperty 3669
ObjectProperty 2818
33145 Objects
// 変数を追加したBP
Function 4557 -> +1
StructProperty 5734 -> +2
BoolProperty 4384 -> +1
FloatProperty 3670 -> +1
ObjectProperty 2819 -> +1
33151 Objects
追加した変数のbool, float, struct, Objectは分かるけど、
もう一個のstructとfunctionはどこから……?
ノードを追加してみた
- GCログ
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.008874 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004161 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (187 -> 187)
// Spawn後
LogBlueprintUserMessages: [NewMap_C_2] Spawn
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006657 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.003882 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (189 -> 189)
// Destroy後
LogBlueprintUserMessages: [NewMap_C_2] Destroy
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006933 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.003882 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.015806 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (189 -> 187)
Spawn前のGC対象のオブジェクトが175から187に増えた
Spawnした後のGC対象のオブジェクトは189。増える量は変わらない
- 増えた12個分のGC対象
// 変数を追加したBP
Function 4557
StructProperty 5734
FloatProperty 3670
IntProperty 1748
33151 Objects
// ノードを追加したBP
Function 4559 -> +2
StructProperty 5735 -> +1
FloatProperty 3678 -> +8
IntProperty 1749 -> +1
33163 Objects
Function 2つはAddとSetFloat?
Float 8つは[New Ver 1]ノード、 [DeltaSeconds]ピン、AddノードのOutputピン*6?
StructとIntが増えたのは何?
マクロ化してみた
- GCログ
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.007488 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004437 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (187 -> 187)
// Spawn後
LogBlueprintUserMessages: [NewMap_C_2] Spawn
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.009980 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004716 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (189 -> 189)
// Destroy後
LogBlueprintUserMessages: [NewMap_C_2] Destroy
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.009704 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004712 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.012200 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (189 -> 187)
ノード単品の時と一緒
マクロの数を増やしてみた
繋げているマクロを3つから5つに増やしてみた
// Spawn前LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006657 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004988 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (191 -> 191)
4つ増えた。Floatピン2つ×マクロ2つ分
関数化してみる
- GCログ
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.008039 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.005268 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (184 -> 184)
// Spawn後
LogBlueprintUserMessages: [NewMap_C_2] Spawn
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.011925 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.003606 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (186 -> 186)
// Destroy後
LogBlueprintUserMessages: [NewMap_C_2] Destroy
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006098 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004437 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.011370 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (186 -> 184)
マクロに比べて、ベースが187から184に減った
- 減った3個分のGC対象
// 変数を追加したBP or マクロ化BP
Function 4559
FloatProperty 3678
33163 Objects
// 関数化BP
Function 4560 -> +1
FloatProperty 3674 -> -4
33160 Objects
別々のノードだったFloatが減って、新規作成したFunction分が増えた
マクロ内のノードは別々のノードとして扱われて、関数内のノードは同一ノードとみなされてPropertyが減る
関数の数を増やした場合
繋げている関数を3つから5つに増やしてみた
// Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.008043 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004161 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (184 -> 184)
GC対象の数は変わらない
BPのGC対象が増えるタイミング
上記のようにSoftReferenceにしてBPのロードを明示化
- GCログ
// ロード前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006378 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.005826 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (173 -> 173)
// ロード後、Spawn前
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.006653 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.003882 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (195 -> 195)
// Spawn後
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.009704 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.003882 ms for Gather Unreachable Objects (0 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: GC purged 0 objects (197 -> 197)
// Destroy後
LogGarbage: Collecting garbage (GCheckForIllegalMarkPendingKill = 1)
LogGarbage: Verbose: 0.010535 ms for Mark Phase (11 Objects To Serialize
LogGarbage: 0.004161 ms for Gather Unreachable Objects (2 objects collected including 0 cluster objects from 0 clusters)
LogGarbage: 0.012476 ms for incrementally unhashing unreachable objects. Items 2 (2/2)
LogGarbage: GC purged 2 objects (197 -> 195)
BPアセットをロードしたタイミングで、BPの変数、ロジックに使用されているプロパティ系列が生成されてGC対象に追加されている
まとめ
今回の検証分の範囲、でのまとめになります
- BP内の変数/関数等ノードはSpawn時のGCに影響しない
- よって、1個Spawnしようが100個Spawnしようが変動しない
-
Spawn時にGC対象が増えるのは、Actor、Component。
- 大量にSpawnする必要がある場合は、Componentを纏めた方がいい
- 50個のComponentで100体出現すると5000個のGCオブジェクトに
- 大量にSpawnする必要がある場合は、Componentを纏めた方がいい
- 変数、関数、ノード(Outputピン?)がアセットとしてのGC対象になる
-
マクロを使うと、内部のノードが展開される都合上、ノードのGC対象が増える
- 使用箇所が複数ある場合は関数を使った方がGC的に良い
- GCコストが高くてどうしてもGC対象を削りたい場合
- 変数、関数、ロジックをC++に持っていく。GC対象の数が減るので検索コストは下がりそう
- その場合はUPROPERTYは付けたら駄目(のハズ)
- 使わないBPアセットとかをロードしない
- Cluster化したら多分Actor単位での検索になるので楽になるはず(今回は未検証
- 変数、関数、ロジックをC++に持っていく。GC対象の数が減るので検索コストは下がりそう
- アセットロード/Spawn/Destroyが無ければ(UE4内部的にも)、GC対象や削除対象は増減しない
- 新規Level+GameModeBaseで放置していてもGC対象の数は勝手に増えない
- 音ゲーとかカクついたらアウトなシーンは注意
常駐化するテクスチャとかパーティクルとかをGC対象から除外する方法ないのかな……
gc.MaxObjectsNotConsideredByGCはPreInit時点っぽいし
PreInit後は駄目です…ただ簡単なコード変更でPreInit後もロードしたオブジェクトをDisregard対象にすることは可能です 。GameInstance::InitはPreInitの後な気がしますが、ちょっとコード見てみます!
— おかず (@pafuhana1213) 2018年12月9日