Why swapping buffers takes different amounts of time?

When my program starts, almost nothing is on screen, just couple of lights and spheres. My FPS is at ~50. The Speed measurements looks like this:

UpdateFrame took 0 ms
Clearing lights queue: 0 ms
Queue floor for rendering: 0 ms
Clearing and starting deferred: 0 ms
base.OnRenderFrame: 0 ms
ModelRenderer.Render (): 0 ms
LightingEngine.RenderFrame (): 0 ms
deferred.RenderOnScreen (): 0 ms
Gui.Render (): 1 ms
SwapBuffers (): 18 ms
ModelRenderer.Clear (): 0 ms

Whole rendering took: 19 ms


But then after a while the program has been running for some time and more lights and spheres are added, the FPS is ~40 and the speed measurements are as follows:

UpdateFrame took 0 ms
Clearing lights queue: 0 ms
Queue floor for rendering: 0 ms
Clearing and starting deferred: 0 ms
base.OnRenderFrame: 5 ms
ModelRenderer.Render (): 4 ms
LightingEngine.RenderFrame (): 7 ms
deferred.RenderOnScreen (): 0 ms
Gui.Render (): 0 ms
SwapBuffers (): 7 ms
ModelRenderer.Clear (): 0 ms

Whole rendering took: 23 ms


I had VSYNC off for this test. This clearly implies that my GPU has too much to chew. I want to know why the SwapBuffers() is taking less time with more stuff on screen, shouldn't it take more or equal time then?

OpenGL sometimes defers your commands until later -- when you see a 0 ms runtime for a particular GL operation, it doesn't mean that operation took 0 ms, it just means that function call (which may have simply queued an operation, not did an actual GPU operation) took a small amount of time. See glFlush().

So, it depends on what work is being done where. SwapBuffers requires all queued work be complete (to actually display the frame), so depending on how much work got done earlier in the frame, more or less work will have to be done at the time that SwapBuffers is called.

Also, another reason you'll see this type of difference and apparent jumps in the SwapBuffers call is because SwapBuffers likely waits for VSYNC. If your VSYNC is 60 Hz, and actual frame render time jitters between 15ms and 17 ms, then on the 15 ms frame, you will see a frame rate of 60 FPS, and for the frame that took 17ms, one VSYNC will be missed, so you'll have to wait for the next one, apparently halving the frame rate (for those 2 frames).

So you're going to have jumps between 60 FPS and 30 FPS, which averages out to about 45 fps, depending on how many 60FPS frames you got, and 30 FPS frames you got.

• I had set the vsync off for that test, which I forgot to mention in the new edited question. Thanks for the glFlush(), I had never heard about that one. Could I be better off, if I called the SwapBuffers() right before I do any opengl drawing calls, instead of right after them. And then call glFlush() right after all drawing calls? Would this let my code be able to work on the game mechanics stuff while the gpu would be drawing the scene? – Lasse Nov 24 '13 at 22:03
• I tried my idea now, and it most definitely did something, as my CPU fan started screaming (which it did not do previously). I'll have to do more research. – Lasse Nov 24 '13 at 22:12

My guess would be that you're GPU bound. Looking at CPU side timings when you're GPU limited won't tell you very much - a lot of that CPU time will be spent idle waiting for the GPU.

What you need is some kind of GPU profiler to tell you what's going on

• I have linux, and I wonder if the nSight eclipse edition can work standalone with mono programs? – Lasse Nov 24 '13 at 18:10
• I updated my question to show what I actually wanted to ask. – Lasse Nov 24 '13 at 18:40
• I don't have Linux. Why not try it and see if it works? – Adam Nov 24 '13 at 20:04
• Because I'd like not to install java and eclipse for nothing if it does not work. – Lasse Nov 24 '13 at 20:07
• @Lasse You can also add timer queries to your app to measure and report GPU timings. That may be easier than getting an external profiler to work. – Nathan Reed Nov 24 '13 at 21:04