Difficulties interpreting profiler timeline

I'm profiling a game and I have some difficulties interpreting the profiler results. I turned to the timeline, which raised some interesting questions:



1) and 2) These regions of the CPU profiler are completely idle on all the threads. First thought would be that the CPU is idle and waiting for the GPU to do it's rendering. However, that doesn't seem to make sense because section 1 occurs between the normal Update() methods but before Camera.Render occurs. Also, once the command buffers have been submitted to the GPU, it should start processing the next frame, there's not really any reason to wait for that process to be completed before using the CPU again.

3) The CPU time is listed at top as 117 ms, but this frame takes 236 ms according to the timeline. The stats number changes when the game is paused, which means the numbers definitely don't correspond to the current frame but it sits roughly at this:

So the CPU time doesn't really count these large blocks of idle time.. But the 8.9 FPS counter isn't really correct if the frames are taking 236 ms.. it should be more like 4.2 FPS. It kind of throws all the numbers into suspicion.

4. The tiny stuff at the end is:

I'm not sure if that is useful or if it implies that we're using that large section of 2) to wait for the frame.. But there's nothing interesting there like reading out of the framebuffer or anything like that, so nothing should block.

This is a very typical frame. Sometimes the "CPU time" is ~110 ms, but the actual total frame time is 300 ms. http://kortham.net/temp/upshot_8RHGOb0M.png

Does this mean my game is GPU bound or CPU bound? Why do they seem to be synchronous (CPU and GPU alternating).

This was done on a MacBook Pro, GeForce GT 650M. The GPU profiler is unavailable on my system.
Thanks in advance!

 

To followup, I ran the project on a windows computer. The idle times are still present, but they are drastically reduced. On the Mac the idle time per frame was between 51% and 61%. On Windows it's about 9% for a typical frame.



Any ideas?

 

Any chance you profiled in the editor? Because profiling in the editor often leads to incorrect results. If that's the case, I recommend to profile a build, since the performance characteristics between editor and player are often significant. Make sure to disable V-sync and any frame-rate limit as well while profiling.

According to the recent screenshot, the game spends about 80ms on the main-thread. Unity processes script-code (game code) on the main thread. Which probably means, if all multi-threaded engine systems finished their work, those worker threads start to idle, because there is no work left for them in this frame.

You could check in the player settings whether you have "Graphic Jobs (Experimental)" enabled, which might improve performance in the rendering pipeline, but I would actually try to fix the issue first.

I would look into ...

• Why 34ms is spent in BehaviourUpdate (script code)
• Why 22ms is spent into CoroutineDelayCalls (script code)
• Why rendering takes so long (according to the stats window, I guess to many single object draw-calls)

Once these problems are fixed, where "fixed" refers to the game runs in your target frame-rate, which might be 30 or 60fps, I'd start to look into the worker thread utilization.

 

Thanks Peter77. The 44+45ms CPU usage in BehaviourUpdate and Coroutines is expected in this scene (the top profile run on the Mac). It's a worst case scenario with a lot of agents doing pathfinding. The additional ~90 ms of idle time is the part I am concerned about. Why wouldn't it start the next frame if all the threads are idle? Yes, it's not close to 60 fps right now, but moving from 236.4 ms per frame to 117 ms per frame in this example would be a big improvement.

Graphics Jobs are off. I did try turning it on, but it had no discernable effect on the timeline or other numbers reported by the profiler.. (I'm using the OpenGLCore renderer). It's my understanding it has no effect on that renderer. See https://forum.unity3d.com/threads/what-is-graphics-jobs-experimental.393433/

Good suggestion about profiling a separate build. I will try that. I don't believe these idle thread times can be caused by VSync since they are drastically larger than 16 ms.

 

Awesome suggestion, @Peter77! The idle time has all but disappeared outside the editor!


out of 167 ms frame time, 163 ms were accounted for by the CPU profiler.

Perhaps the idle time was actually used by the editor... for something. (The scene view was closed, which drastically improves the performance in the editor).

For the benefit of other people who might find this thread, I'd like to share a non-worst case frame also:


A few important things that make sense (that weren't happening in the editor):
1) The main thread is "busy" the whole time.
2) The next frame starts as soon as the highlighted frame is done. (After the Camera.Render there's a tiny PlayerEndOfFrame)
3) the RenderThread can submit the highlighted frame while the main thread is processing the next frame.
4) There is a GFX.WaitForPresent that's significant in the current highlighted frame. It's waiting for the renderthread to be done with the previous frame. In more complicated scenes the BehaviourUpdate is longer than 1.44 ms, so the main thread waiting there will be consumed by actual game logic, so I'm not at all worried about it.

I think I can confidently conclude that I shouldn't profile these issues in the editor. Thanks Peter