ParticlesParallelFor profiling hotspot performance fix?

I get random lag/hang/stutter/hiccups. From the stats, it seems to be - maybe - cascade particles, and there is some collision being checked, if the names of these functions are to be taken at face value. I have already gone through the particle fx I am using and removed any lighting or collision modules I could find. (I wish there were “find in particles” and “find in materials” akin to “find in blueprints”?!"!?!?!).

a) am i interpreting this at all right?
b) how can i find the offending particle system?

sincere thanks for any education, i am too ignorant in the ways of unreal.

“Event Name”,“Inc Time (MS)”,“Inc Time (%)”,“Exc Time (MS)”,“Exc Time (%)”,“Calls”,“None”,
“Background Worker #2 [0x7bc]”,“102.710 ms”,“106.2 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPhysicsSolverAdvanceTask”,“91.856 ms”,“89.4 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Physics Tick”,“91.856 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Evolution/Kinematic update and forces”,“91.774 ms”,“99.9 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPBDRigidsEvolutionGBF::AdvanceOneTimeStep”,“91.768 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPBDRigidsEvolutionGBF::DetectCollisions”,“90.914 ms”,“99.1 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Collisions::Detect”,“90.913 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Collisions::BroadPhase::Spatial”,“90.906 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“ParticlesParallelFor”,“90.904 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“ParticleViewParallelForImp”,“90.904 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“ParallelFor”,“90.899 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,

https://github.com/EpicGames/UnrealEngine/search?q=particlesparallelfor

https://github.com/EpicGames/UnrealEngine/blob/cdaec5b33ea5d332e51eee4e4866495c90442122/Engine/Source/Runtime/Experimental/Chaos/Public/Chaos/ParticleIterator.h#L28

// The function ParticlesParallelFor may be called on ParticleViews, HandleViews,
// or plain old manually curated arrays of either.

that doesn’t make me understand yet since i know zero about unreal source code, but now i am wondering if the collision that is taking so long is not particles per se, but maybe some of my regular actors via HandleViews?

When I try to use the in-game various “stat” console commands (gpu, cpu, physics, etc.) I have not yet seen what the contributing factor is. The World Tick Time & Tick Time go way up randomly but nothing else that I’ve seen yet is spiking along with it. So confused.

overall at least it does not look to be gpu bound / render thread, those always have a cpu stall wait for events, and the FDrawSceneCommand is not really ever over 20ms.

“stat dumphitches” reports multiple times. I am not sure how to interpret the info yet. Frustratingly hard to parse since it is an ascii dump so i can’t directly expand/collapse the tree to understand what-is-a-child-of-what. Doesn’t yet seem to have a 100% consistent reason in the dump but i see things like:

  • LogStats: 129.762ms ( 1) - CollectGarbageInternal - STAT_CollectGarbageInternal - STATGROUP_GC - STATCAT_Advanced

  • LogStats: 51.629ms ( 41) - UpdateLevelStreaming Time - STAT_UpdateLevelStreamingTime - STATGROUP_StreamingDetails - STATCAT_Advanced

  • LogStats: 60.307ms (1584) - Shape Bidirectional Text - STAT_SlateShapeBidirectionalText - STATGROUP_Slate - STATCAT_Advanced

also see this which is confusing to me, is this akin to a Wait For Tasks? But there’s nothing else in the thread hitch dump that is large, so i don’t see what this is pointing to really.

LogStats: 333.302ms ( 4) - Thread_1ab8_0 - GameThread - STATGROUP_Threads - STATCAT_Advanced
LogStats: 333.298ms ( 2) - FrameTime - STAT_FrameTime - STATGROUP_Engine - STATCAT_Advanced
LogStats: 305.687ms ( 1) - STAT_FEngineLoop_UpdateTimeAndHandleMaxTickRate - STATGROUP_Quick - STATCAT_Advanced
LogStats: 305.652ms ( 1) - Game thread tick wait time - STAT_GameTickWaitTime - STATGROUP_Threading - STATCAT_Advanced
LogStats: 305.651ms ( 1) - Game thread idle time - STAT_GameIdleTime - STATGROUP_Threading - STATCAT_Advanced
LogStats: 0.001ms ( 1) - OtherChildren
LogStats: 0.035ms ( 1) - OtherChildren

Hm. Some of the DumpHitches output looks like a lot of my actors “starting up”. I have a open world. I ended up putting most of them in a level streaming level “because reasons”. (I did do a test where i moved everything back to the primary level even tho that breaks so much, just to see, and i still got a lot of hiccups, so it did not seem to prove that level streaming is a main culprit.) But in this hang that was like 2000ms (!) i see UserConstructionScript etc., for a whole lot of actors. I wish I knew if there were a way to force any and all startup to happen more explicitly before the user can start playing, if indeed this is the issue.

p.s. i do see hitches in packaged shipping & development builds, not just in-editor (i have launched the editor with -noverifygc and -noailogging fwiw in case that helps me avoid fake hitches, but).

running a Development packaged exe with -noailogging and -noverifygc, then hitting ~ inside the game and doing stat dumphitches, i see basically all the same stuff i see in PIE. one thing that really puzzles me is there are cpu waits but they don’t say what they are waiting on and i don’t see anything obvious in the dump. both the game and render thread hit a cpu stall wait for event.

[2023.02.06-02.23.58:972][398]LogStats: ------------------Thread Hitch 6, Frame 1399   103.4ms ---------------
[2023.02.06-02.23.58:983][398]LogStats: ------------------ Game Thread 103.43ms
[2023.02.06-02.23.58:983][398]LogStats:   103.410ms (   4)  -  Thread_45ec_0 - GameThread - STATGROUP_Threads - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:     103.407ms (   2)  -  FrameTime - STAT_FrameTime - STATGROUP_Engine - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:       102.981ms (   1)  -  GameEngine Tick - STAT_GameEngineTick - STATGROUP_Engine - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:         102.256ms (   1)  -  World Tick Time - STAT_WorldTickTime - STATGROUP_Game - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:           101.683ms (   4)  -  Tick Time - STAT_TickTime - STATGROUP_Game - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:             93.309ms (   1)  -  TG_EndPhysics - STAT_TG_EndPhysics - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:               93.305ms (   1)  -  ReleaseTickGroup Block - STAT_ReleaseTickGroup_Block - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                 92.807ms (   2)  -  Game TaskGraph Stalls - STAT_TaskGraph_GameStalls - STATGROUP_Threading - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                   92.806ms (   2)  -  CPU Stall - Wait For Event - STAT_EventWait - STATGROUP_CPUStalls - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                   0.002ms (   2)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:                 0.498ms (   7)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:               0.004ms (   3)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:             6.598ms (   1)  -  TG_PrePhysics - STAT_TG_PrePhysics - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:               6.530ms (   1)  -  ReleaseTickGroup Block - STAT_ReleaseTickGroup_Block - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                 6.456ms (   1)  -  Game TaskGraph Tasks - STAT_TaskGraph_GameTasks - STATGROUP_Threading - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                   6.067ms ( 613)  -  FTickFunctionTask - STATGROUP_TaskGraphTasks - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:                     6.067ms (1226)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:                   0.389ms (   6)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:                 0.075ms (   2)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:               0.067ms (   3)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:             1.776ms (  12)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:           0.574ms (  11)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:         0.725ms (  15)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:       0.426ms (  21)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats:     0.003ms (   2)  -  OtherChildren
[2023.02.06-02.23.58:983][398]LogStats: ------------------ Render Thread (//STATGROUP_Threads//RenderThread///Thread_4d8c_0///####STATCAT_Advanced####) 102.59ms
[2023.02.06-02.23.58:983][398]LogStats:   102.402ms ( 418)  -  Thread_4d8c_0 - RenderThread - STATGROUP_Threads - STATCAT_Advanced
[2023.02.06-02.23.58:983][398]LogStats:     89.263ms (  17)  -  CPU Stall - Wait For Event - STAT_EventWait - STATGROUP_CPUStalls - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:     11.675ms (   1)  -  FDrawSceneCommand - STATGROUP_RenderThreadCommands - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:       11.364ms (   1)  -  RenderViewFamily - STAT_TotalSceneRenderingTime - STATGROUP_SceneRendering - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:         5.368ms ( 184)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:         3.876ms (   1)  -  Execute - STAT_RDG_ExecuteTime - STATGROUP_RDG - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:           1.567ms ( 287)  -  STAT_FRDGPass_Execute - STATGROUP_Quick - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:             1.567ms ( 321)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:           1.363ms (   4)  -  All Command List Execute - STAT_ImmedCmdListExecuteTime - STATGROUP_RHICMDLIST - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:             1.363ms (  18)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:           0.946ms (   1)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:         2.120ms (   1)  -  UpdatePrimitive - STAT_UpdateScenePrimitiveRenderThreadTime - STATGROUP_SceneUpdate - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:           1.874ms (   1)  -  UpdatePrimitiveTransform - STAT_UpdatePrimitiveTransformRenderThreadTime - STATGROUP_SceneUpdate - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:             1.394ms (   3)  -  ParticleSystem/Game/InfinityBladeEffects/Effects/FX_Treasure/Chest/P_TreasureChest_CallOut_loop.P_TreasureChest_CallOut_loop - STATGROUP_UObjects - STATCAT_Advanced
[2023.02.06-02.23.58:984][398]LogStats:               1.394ms (   3)  -  Self
[2023.02.06-02.23.58:984][398]LogStats:               0.000ms (   3)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:             0.480ms ( 225)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:           0.245ms (   9)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:       0.311ms (   5)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats:     1.464ms ( 400)  -  OtherChildren
[2023.02.06-02.23.58:984][398]LogStats: ----------------------------------------
[2023.02.06-02.23.58:984][398]LogStats: Events history: Single frame 1399, greater than 1.0 ms
[2023.02.06-02.23.58:984][398]LogStats: Displaying events history for GameThread
[2023.02.06-02.23.58:984][398]LogStats: Displaying events history for RenderThread
[2023.02.06-02.23.58:984][398]LogStats: Duration: 5.55 MS
[2023.02.06-02.23.58:984][398]LogStats:  Wait   : RenderThread
[2023.02.06-02.23.58:984][398]LogStats:  Trigger: TaskGraph_EnqueueFromOtherThread_Trigger <- Component DestroyPhysicsState <- StaticMeshComponent/Game/FirstPersonBP/Maps/FirstPersonExampleMap.FirstPersonExampleMap.PersistentLevel.spooge_C.spooge <- UnregisterComponent <- spooge_C/Game/FirstPersonBP/Maps/FirstPersonExampleMap.FirstPersonExampleMap.PersistentLevel.spooge_C <- Destroy Actor <- spooge_C/Game/FirstPersonBP/Maps/FirstPersonExampleMap.FirstPersonExampleMap.PersistentLevel.spooge_C <- FTimerManager <- GT Tickable Time <- World Tick Time <- GameEngine Tick <- FrameTime <- GameThread
[2023.02.06-02.23.58:986][398]LogStats: ----------------------------------------

my own ‘coding’ for this is entirely blueprints, i haven’t touched c++ at all. … currently wondering if this is a GC issue. i am deleting swaths of things in my app to see if that makes a difference, and e.g. turning off all ‘spooge’ actors that got generated did seem to delay the hiccup, which sorta then feels like a gc thing. the hitch dumps do often (but not always!) have gc functions in them.

I see hitches that have wait for event, but no way to see what the event actually is afaict.

[2023.02.06-03.57.50:403][405]LogStats: ------------------Thread Hitch 2, Frame 1406    68.3ms ---------------
[2023.02.06-03.57.50:415][405]LogStats: ------------------ Game Thread 68.27ms
[2023.02.06-03.57.50:415][405]LogStats:   68.258ms (   4)  -  Thread_3c5c_0 - GameThread - STATGROUP_Threads - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:     68.256ms (   2)  -  FrameTime - STAT_FrameTime - STATGROUP_Engine - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:       67.717ms (   1)  -  GameEngine Tick - STAT_GameEngineTick - STATGROUP_Engine - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:         67.007ms (   1)  -  World Tick Time - STAT_WorldTickTime - STATGROUP_Game - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:           66.710ms (   4)  -  Tick Time - STAT_TickTime - STATGROUP_Game - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:             61.761ms (   1)  -  TG_EndPhysics - STAT_TG_EndPhysics - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:               61.757ms (   1)  -  ReleaseTickGroup Block - STAT_ReleaseTickGroup_Block - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                 61.396ms (   2)  -  Game TaskGraph Stalls - STAT_TaskGraph_GameStalls - STATGROUP_Threading - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                   61.394ms (   2)  -  CPU Stall - Wait For Event - STAT_EventWait - STATGROUP_CPUStalls - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                   0.002ms (   2)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:                 0.361ms (   7)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:               0.004ms (   3)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:             3.797ms (   1)  -  TG_PrePhysics - STAT_TG_PrePhysics - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:               3.753ms (   1)  -  ReleaseTickGroup Block - STAT_ReleaseTickGroup_Block - STATGROUP_TickGroups - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                 3.703ms (   1)  -  Game TaskGraph Tasks - STAT_TaskGraph_GameTasks - STATGROUP_Threading - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                   3.431ms ( 452)  -  FTickFunctionTask - STATGROUP_TaskGraphTasks - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:                     3.431ms ( 904)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:                   0.273ms (   6)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:                 0.050ms (   2)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:               0.044ms (   3)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:             1.152ms (  11)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:           0.297ms (  10)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:         0.710ms (  15)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:       0.539ms (  22)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:     0.002ms (   2)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats: ------------------ Render Thread (//STATGROUP_Threads//RenderThread///Thread_2174_0///####STATCAT_Advanced####) 68.24ms
[2023.02.06-03.57.50:416][405]LogStats:   68.104ms ( 345)  -  Thread_2174_0 - RenderThread - STATGROUP_Threads - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:     55.180ms (  10)  -  CPU Stall - Wait For Event - STAT_EventWait - STATGROUP_CPUStalls - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:     11.364ms (   1)  -  FDrawSceneCommand - STATGROUP_RenderThreadCommands - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:       11.045ms (   1)  -  RenderViewFamily - STAT_TotalSceneRenderingTime - STATGROUP_SceneRendering - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:         5.143ms ( 149)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:         3.372ms (   1)  -  Execute - STAT_RDG_ExecuteTime - STATGROUP_RDG - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:           1.297ms ( 299)  -  STAT_FRDGPass_Execute - STATGROUP_Quick - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:             1.297ms ( 333)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:           1.204ms (   4)  -  All Command List Execute - STAT_ImmedCmdListExecuteTime - STATGROUP_RHICMDLIST - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:             1.204ms (  18)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:           0.871ms (   1)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:         2.530ms (   1)  -  UpdatePrimitive - STAT_UpdateScenePrimitiveRenderThreadTime - STATGROUP_SceneUpdate - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:           2.420ms (   1)  -  UpdatePrimitiveTransform - STAT_UpdatePrimitiveTransformRenderThreadTime - STATGROUP_SceneUpdate - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:             1.941ms (  16)  -  ParticleSystem/Game/InfinityBladeEffects/Effects/FX_Mobile/Fire/combat/P_AuraCircle_Fire_02.P_AuraCircle_Fire_02 - STATGROUP_UObjects - STATCAT_Advanced
[2023.02.06-03.57.50:416][405]LogStats:               1.941ms (  16)  -  Self
[2023.02.06-03.57.50:416][405]LogStats:               0.001ms (  16)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:             0.479ms ( 184)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:           0.110ms (   4)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:       0.319ms (   5)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats:     1.559ms ( 334)  -  OtherChildren
[2023.02.06-03.57.50:416][405]LogStats: ----------------------------------------
[2023.02.06-03.57.50:416][405]LogStats: Events history: Single frame 1406, greater than 1.0 ms
[2023.02.06-03.57.50:416][405]LogStats: Displaying events history for GameThread
[2023.02.06-03.57.50:416][405]LogStats: Displaying events history for RenderThread
[2023.02.06-03.57.50:416][405]LogStats: Duration: 6.54 MS
[2023.02.06-03.57.50:416][405]LogStats:  Wait   : RenderThread
[2023.02.06-03.57.50:416][405]LogStats:  Trigger: TaskGraph_EnqueueFromOtherThread_Trigger <- World Tick Time <- GameEngine Tick <- FrameTime <- GameThread

…still at a loss to grok. “stat gc” indicates it is not a gc problem. “stat quick” does not show anything bad either.

omg Reddit - Dive into anything
this is like the only answer i have ever managed to find anywhere that remotely seems to make a “helpful or intelligible” comment about this at all, wth? how can this be such a completely hidden mystery secret cult type information that isn’t well documented or discussed openly given how many people seem to inevitably run into exactly this kind of problem with profiling? (if in fact this is a valid piece of info.)

cpu stall - wait for event means something a frame or two earlier is EXCESSIVELY long and the cpu does nothing for the next frame while waiting to catch up.

welp, based on that i am guessing i can ignore the ParallelFor stuff because there’s a ParallelFor.Wait, maybe that is akin to CPU stalling on Wait for Event or WaitForTask et. al. … so something else is killing the fps. Looking at Unreal Insights graphs, it seems like the UWorld_Tick starts before the Frame starts, presumably to calculate the new frame to render. The UWorld_Tick row always extends into the next Frame, so that in and of itself is no obvious red flag. I guess sometimes the UWorld_Tick row goes way too far into the next Frame which then pushes the fps to drop, but I can’t yet understand how to know exactly what is the bad thing taking up the time, nor can I see from the graph how to know when a UWorld_Tick took up too much time, other than by working backwards from slow fps frames.

i sure wish it were easier to compare slow vs. fast frames in Unreal Insights. it seems to have so much it can help me see but then sorta falls down when i get to the point of trying to diff frame traces to desperately hope i could possibly ever see what the salient differences are, that might be the culprit in the frame rate drops.

turning on more traces (created Development packaged app, ran it using a Windows shortcut set up like so: C:\Users\x\Documents\Windows\x.exe -noverifygc -noailogging -trace=log,counters,cpu,frame,bookmark,file,loadtime,gpu,rhicommands,rendercommands,object -statnamedevents) it looks to me like perhaps it is a physics / collision thing taking up the time. But I am not sure / i am confused / i am frustrated becuase the bottom of that stack os PArallelFor.Wait, so i am not sure if that implies it is waiting for something else that is being slow/late?!?!?!?!?!?!!!

in Unreal Insights, the ParallelFor.Wait at the bottom of the Chaos Physics trace seems to me to (grasping at straws i am) be blocked on nothing else visible in the traces i have enabled at least. So it looks like some lock is held way too long, or some such?! UE 5.1, Windows 10, gtx 980 or rtx 2070 mobile max q are my test machines.

sure i am already in a bad depressed mood over all this but it doesn’t help that github ui ux is such an epic train fail wreck like searching for “parallelfor.wait” turns up zero code results and it was only through some comments from commits that i could track down this line of code: https://github.com/EpicGames/UnrealEngine/blob/c7a12ff0f86d3de33eb47725b78ad63a97838766/Engine/Source/Runtime/Core/Public/Async/ParallelFor.h#L372

I would like that to somehow log what the last task was, so i could maybe have a snowball’s chance in heck of finding out why the bleedin’ parallel for is hung up. throw me a bone.

I attempted to build Unreal Editor from open source, that was in various ways a very dead end. Went back to my commits and did a manual ‘bisect’ in the hopes the problem was deterministic. Did find a commit where things got bad. Unfortunately Unreal seems to keep everything in binary files that are hard to diff. Fortunately the change list included a few individual usasset files. I deleted them one by one in the game etc., found a culprit that empirically made things bad/good. Might have been that some of the scene components in that actor had needless collision. After I disabled that collision things appear to be knock on wood fingers crossed no longer hitching. (until the next thing that does…) Overall I don’t think I ever found a strongly clear signal about where to look from any of the debugging tools unfortunately so I don’t have great advice in that regard so saying this is [solved] feels potentially unhelpful for anybody else who comes across this thread because they are trying to resolve a similar issue.

spoke too soon? i am hitting it again after what seemed like my fix. :frowning:

(there’s no way to mark this thread as not solved? i can’t figure that out if there is.)

“Event Name”,“Inc Time (MS)”,“Inc Time (%)”,“Exc Time (MS)”,“Exc Time (%)”,“Calls”,“None”,
“ParallelFor”,“51.219 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Foreground Worker #1 [0x4af0]”,“70.499 ms”,“125.4 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPhysicsSolverAdvanceTask”,“51.997 ms”,“73.8 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Physics Tick”,“51.996 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Evolution/Kinematic update and forces”,“51.881 ms”,“99.8 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPBDRigidsEvolutionGBF::AdvanceOneTimeStep”,“51.877 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“FPBDRigidsEvolutionGBF::DetectCollisions”,“51.229 ms”,“98.8 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Collisions::Detect”,“51.228 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“Collisions::BroadPhase::Spatial”,“51.224 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“ParticlesParallelFor”,“51.222 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,
“ParticleViewParallelForImp”,“51.222 ms”,“100.0 %”,“0.000 ms”,“0.0 %”,“1.0”,

ok ok ok so it looks like it really was that object i had tracked it down to, when i did the bisection tests of various saved versions of the game. and it does look like it was issues where small components of the actor had collision enabled when i did not want them to, and they must have been crashing into things enough to freak out the engine. disabling their collision once again seems to have been the solution fingers crossed.