Understanding QSG_RENDER_TIMING

Janna

Hi,

I am trying to understand why my qt gui gets slow downs sometimes.
In order to understand the timing giving by QSG_RENDER_TIMING
I have run Custom Geometry Example
in QtCreator and I got timings like this:

renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
.renderloop: Frame rendered with 'basic' renderloop in 10ms, polish=0, sync=0, render=0, swap=0, frameDelta=16

renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'basic' renderloop in 15ms, polish=0, sync=0, render=0, swap=1, frameDelta=34

if polish sync render and swap is only 1ms, where is the rest of the timing comes from? I am on Qt 5.5.1 and looking over renderWindow() source code it looks like those timings should add up. I am getting similar situation in my own Qt code , once in a while I get a spike .. instead of 10ms renderloop takes 20ms or more.
I am also wondering why this example would take so much in renderloop?

Thank a lot :)

Janna

I also noticed, this timings I get running at 60fps (16ma update time). If I update QQuickItem at let's say 25ms (Using QTimer to trigger update()) then the timings I get are following:

renderloop: Frame rendered with 'basic' renderloop in 13ms, polish=0, sync=0, render=0, swap=1, frameDelta=32
renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'basic' renderloop in 4ms, polish=0, sync=0, render=0, swap=0, frameDelta=16
renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'basic' renderloop in 13ms, polish=0, sync=0, render=0, swap=1, frameDelta=34

Looks strange
I have tried to change to the threaded model and I see similar timing but now it shows that the time in question was actually in the swap:

renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'threaded' renderloop in 12ms, sync=0, render=0, swap=12 - (on render thread)
renderloop: Frame prepared with 'threaded' renderloop, polish=0, lock=0, blockedForSync=5, animations=0 - (on Gui thread) QQuickView(0x7fff5fa7da78)
renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'threaded' renderloop in 15ms, sync=0, render=0, swap=15 - (on render thread)
renderloop: Frame prepared with 'threaded' renderloop, polish=0, lock=0, blockedForSync=5, animations=0 - (on Gui thread) QQuickView(0x7fff5fa7da78)
renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'threaded' renderloop in 17ms, sync=0, render=0, swap=17 - (on render thread)
renderloop: Frame prepared with 'threaded' renderloop, polish=0, lock=0, blockedForSync=6, animations=0 - (on Gui thread) QQuickView(0x7fff5fa7da78)
renderer: time in renderer: total=0ms, preprocess=0, updates=0, binding=0, rendering=0
renderloop: Frame rendered with 'threaded' renderloop in 20ms, sync=0, render=0, swap=20 - (on render thread)
renderloop: Frame prepared with 'threaded' renderloop, polish=0, lock=0, blockedForSync=11, animations=0 - (on Gui thread)

I am wondering why the swap timing are so all over the place which seems to result in some frames not being able to draw consistently.