Hello,
I did some further investigation to determine what exactly inside flush is causing the high cost, and I noticed two things. I also determined that, the way the function works, time slicing the pending actions wouldn’t be possible, but perhaps time slicing the removal of old pending data might?
One; There is a lot of pending data that is marked as an “Add operation”, when that element is already in the acceleration tree at the exact location that the pending data is computing. This leads me to believe that there is a high amount of duplicate work being done and there’s more pending data then there should be.
Two; The bulk of the cost comes from removing the pending data, looking at the function where we remove an entry from the ExternalQueue, it also makes sense. The function removes at swap FPendingSpatialData whenever the pending data is no longer needed, however when we have a level as large as ours, with as many colliding objects as us, doing this 10k to 100k times in a single function call is very slow.
I’ve added additional logging to get exact numbers, and the logs show the following attached at the bottom.
Data format:
NumPending [NumPendingEntries] Num[Added / Updated / Deleted / Removed], NumBad[Adds / Updates / Deletes], MS[AddTime / UpdateTime / DeleteTime / RemoveTime]
Delete is Delete Operations, remove is removing data from the pending data.
NumBad is where the audits have been commented out (1 bad add = Adding when already in tree)
When inspecting this data I can find that the majority of the time is spent in Add and Remove, where the majority of the add time is accounted for by the duplicate adds. Except for one line (line 13) where the Add time is expensive, all expensive Add times have a high proportion of duplicate adds, leading me to believe it has more pending data than it should.
Secondly, the big bulk of all the time comes from removing pending data, and as I wrote above, the way it’s implemented is very slow for 10-100k entries being removed at once.
Is Epic Games aware of these two performance issues? And if so, is there a timeline for when these could be addressed?
FlushExternalAccelerationQueue, NumPending [24] Num[23 / 0 / 1 / 0], NumBad[23 / 0 / 1], MS[0.0202 / 0.0000/ 0.0008 / 0.0000]
FlushExternalAccelerationQueue, NumPending [439257] Num[354191 / 545 / 84521 / 0], NumBad[303698 / 545 / 3596], MS[265.5232 / 4.2787/ 20.6948 / 0.0000]
FlushExternalAccelerationQueue, NumPending [440325] Num[51225 / 860 / 84521 / 303719], NumBad[49606 / 315 / 84521], MS[26.5078 / 2.0931/ 8.7666 / 4074.1984]
FlushExternalAccelerationQueue, NumPending [136775] Num[42 / 137 / 0 / 136596], NumBad[2 / 2 / 0], MS[0.0550 / 0.2991/ 0.0000 / 439.9897]
FlushExternalAccelerationQueue, NumPending [8407] Num[21 / 40 / 0 / 8346], NumBad[1 / 0 / 0], MS[0.0631 / 0.0484/ 0.0000 / 5.3420]
FlushExternalAccelerationQueue, NumPending [11094] Num[3 / 94 / 1 / 10996], NumBad[2 / 0 / 1], MS[0.0188 / 0.1498/ 0.0006 / 5.0516]
FlushExternalAccelerationQueue, NumPending [4771] Num[225 / 41 / 6 / 4499], NumBad[225 / 0 / 6], MS[0.3314 / 0.0713/ 0.0032 / 1.3826]
FlushExternalAccelerationQueue, NumPending [4987] Num[624 / 29 / 0 / 4334], NumBad[624 / 0 / 0], MS[1.1164 / 0.0518/ 0.0000 / 2.2469]
FlushExternalAccelerationQueue, NumPending [16990] Num[310 / 29 / 0 / 16651], NumBad[310 / 0 / 0], MS[0.2721 / 0.0574/ 0.0000 / 12.8272]
FlushExternalAccelerationQueue, NumPending [10326] Num[0 / 29 / 310 / 9987], NumBad[0 / 0 / 310], MS[0.0000 / 0.0682/ 0.0185 / 4.4128]
FlushExternalAccelerationQueue, NumPending [13265] Num[0 / 34 / 354 / 12877], NumBad[0 / 0 / 117], MS[0.0000 / 0.0535/ 0.0953 / 6.9863]
FlushExternalAccelerationQueue, NumPending [7586] Num[2555 / 56 / 0 / 4975], NumBad[2152 / 11 / 0], MS[2.5343 / 0.1477/ 0.0000 / 1.9040]
FlushExternalAccelerationQueue, NumPending [39801] Num[12575 / 36 / 0 / 27190], NumBad[3920 / 6 / 0], MS[32.4842 / 0.0907/ 0.0000 / 61.2164]
FlushExternalAccelerationQueue, NumPending [13329] Num[595 / 29 / 0 / 12705], NumBad[91 / 0 / 0], MS[0.7244 / 0.0657/ 0.0000 / 9.7775]
FlushExternalAccelerationQueue, NumPending [19203] Num[1552 / 29 / 0 / 17622], NumBad[1532 / 0 / 0], MS[1.5429 / 0.0723/ 0.0000 / 23.9930]
FlushExternalAccelerationQueue, NumPending [40268] Num[2146 / 29 / 0 / 38093], NumBad[2132 / 0 / 0], MS[2.3334 / 0.0740/ 0.0000 / 76.6345]
FlushExternalAccelerationQueue, NumPending [6919] Num[315 / 29 / 0 / 6575], NumBad[315 / 0 / 0], MS[0.3192 / 0.0720/ 0.0000 / 3.5380]
[Attachment Removed]