I'm trying to profile my renderer, and I'm seeing some weird profiling behavior that I can't explain.
I'm using a glSurfaceView, which I have set to render continuously.
This is how my onDrawFrame()
is structured
public void onDrawFrame(GL10 unused) {
GLES20.glClear(GLES20.GL_COLOR_BUFFER_BIT | GLES20.GL_DEPTH_BUFFER_BIT);
executeAllDrawCommands();
}
This was behaving slowly under light load, so I created a timer class and started to profile this some. I was quite surprised by what I saw.
I put some probes on my onDrawFrame method like so:
public void onDrawFrame(GL10 unused) {
swapTimer.end();
clearTimer.start();
GLES20.glClear(GLES20.GL_COLOR_BUFFER_BIT | GLES20.GL_DEPTH_BUFFER_BIT);
clearTimer.end();
drawTimer.start();
executeAllDrawCommands();
drawTimer.end();
swapTimer.start();
}
clearTimer
measures the time it takes to call glClear, drawTimer
measures the time it takes to run all my draw calls, and swapTimer
measures the time from when onDrawFrame exits and when it returns (the time taken to call eglSwapBuffers).
When I ran a very lightly loaded scene, I got some really strange numbers I can't explain:
swapTimer : 20ms (average)
clearTimer : 11ms (average)
drawTimer : 2ms (average)
I expected the swap time to be somewhat largish, as I believe the device has vsync forced enable at ~30fps, though I don't know why the actual 'clear' call is blocking for 11 milliseconds? I thought it was just supposed to issue an asynchronous command and return?
When I draw a much more busy scene, the numbers change quite a bit:
swapTimer : 2ms (average)
clearTimer : 0ms (average)
drawTimer : 44ms (average)
In this scene my draw calls are taking so much time that it looks like its hiding a lot of the vsync period, and the block on the clear call totally goes away.
Is there any explanation for why glClear is blocking on my lightly loaded scene?
Link to my 'Timer' class source code in case someone is suspicious of my measuring technique: http://pastebin.com/bhXt368W
glFinish
(and finishTimer.start()/end() around it), and it takes all the time away from glClear. Instead now glFinish takes some number of milliseconds, and glClear becomes instant. It seems like this is all related to vsync, though I was surprised to see vsync time appear inside of glClear. – Liba