I am using the CsvProfiler (within AutomatedPerformanceTest runs) to log data for various performance benchmarks in my project.
I would like to log the time that UWorld::Tick spends during the individual Tick Groups (PrePhysics, StartPhysics, etc.). The code blocks that execute each Tick Group are already timed with the Stats system (through SCOPE_CYCLE_COUNTER) but these timings are not emitted to CSV. Each block only calls into the CsvProfiler through the CSV_SCOPED_SET_WAIT_STAT macro, which seems to record only the time spent waiting for other threads while within the block and essentially misses the time that the game thread spends doing work within each block. There doesn’t seem to be an easy way to calculate this time (and/or the total wall clock time) for each Tick Group from existing CSV stats.
Is there a specific reason why UWorld logs the wait time for each Tick Group in CSVs but not the total wall clock time? It seems it would be fairly easy to also log the total time (just add a CSV_SCOPED_TIMING_STAT call to each block). I also imagine that this metric is generally considered useful (being already tracked for the Stats system). I can add it locally but I am interested in knowing if this is the wrong approach for some reason, and also if there is value in pushing this change upstream.
> Is there a specific reason why UWorld logs the wait time for each Tick Group in CSVs but not the total wall clock time?
Unfortunately, the simple answer here is “historical reasons” or more simply, no one cared enough to add them.
Those WAIT_STATs were specifically introduced to track waits back when the FN perf team needed this information.
The CSV Profiler is also intended as a low-overhead profiler that works well in test/shipping, so it generally has a lot fewer scopes than our other tools.
That could explain why the regular scopes where never added. In addition to that, CSV profiler instrumentation is primarily driven by the Fortnite team, and the CSV scopes are usually not explicitly maintained by the Engine team.
Usually, we use Unreal Insights if we need to dig deeper into a specific issue and CSVProfiler is only used to get rough information out of Game runs first.
Long ticks are enough of a signal to go looking into Insights, since most of the time you’ll need the extra instrumentation to find out what actor/system is slow during a tick group anyway.
Overall, I don’t think there was any specific reason for not putting these scopes there.
Feel free to add them on your side!
You can definitely send in a PR for the change, but I can’t promise that the Gameplay devs will see enough value in this to accept it. It is a minimal and reasonable change, though, so that definitely improves your chances compared to larger changes.