eglplasma runs at half vsync rate

[Kevin DuBois]

running mesa+bypass+client gives this log on the host server with the --display-report=log and --compositor-report=log gives:

[1425675196.763081] graphics: 31 vsync events on [8] over 1032ms
[1425675196.763766] compositor: Display 0x7f236c332310 averaged 30.033 FPS, 0.000 ms/frame, latency 0.047 ms, 31 frames over 1.032 sec, 100% bypassed

(first discovered on lttng traces)
on my i965 laptop.

[Kevin DuBois (kdub)]

lttng trace of problem

[Kevin DuBois (kdub)]

so I guess my hardware is missing the deadline to drive the host compositor at 60fps with eglplasma, and it cuts us the display driven rate down to 30fps.

Problem does not happen with triple buffering, or even with egltriangle, which runs faster than eglplasma.
Fullscreen is 1280x800 on my computer, and even shaving the eglplasma canvas to 1100x800 will get me back up to 60fps.

[Kevin DuBois (kdub)]

So, I guess this is a tradeoff of triple v double buffering... not sure if this is a bug, or a wishlist for the dynamic switching between double and triple buffering.

[Daniel van Vugt (vanvugt)]

I have dynamic switching working, but not yet completed:
  https://code.launchpad.net/~vanvugt/mir/ddouble

Theoretically though, what you're experiencing here is correct and arguably desirable. If triple buffering "saves you" it means you're right on the knife's edge of what the host can keep up with. Triple buffering can help in some patterns, but 50% of the time it won't save you. And 100% of the time it will increase latency.

As soon as the client starts rendering something simpler than plasma, your machine will be able to keep up. In that case, double buffering gives half the latency of triple. And frankly most of what we do in Ubuntu should "keep up" and we want minimal latency. eglplasma is an unrealistically demanding shader demo.

But dynamic switching (when finished) would be good.

[Daniel van Vugt (vanvugt)]

What's the GPU?

I assume "i965" refers to the Mesa driver name and not your actual hardware (which is very likely much newer than Intel 965).

[Kevin DuBois (kdub)]

A more complete trace

[Kevin DuBois (kdub)]

> And 100% of the time it will increase latency.

But here we have an instance of double buffering increasing latency. We start to drive the display at 30hz instead of 60hz, so the cost of missing a vsync goes from ~16ms to ~33ms. In this scenario (meaning, the trace data), I see us missing 2 vsyncs and posting on the third, and having a latency of 100ms (from client production to base server posting on screen). With triple buffering, we seem to be missing more vsyncs, but the cost of each is less, and we have a latency of less than 100ms.

[Daniel van Vugt (vanvugt)]

Double buffering skipping frames usually only increases latency to 2; the same as triple buffering when it's not skipping frames. :)

What GPU is it?

If double buffering is missing 2 vsyncs, but triple works, then that sounds like an Intel driver bug I encountered a while back. Traced that to the driver simply sleeping for too many vsyncs:
   https://bugs.launchpad.net/mir/+bug/1377872
   https://bugs.freedesktop.org/show_bug.cgi?id=86366

Try the workarounds I listed in there...

[Daniel van Vugt (vanvugt)]

Also, what is the reported client render time (MIR_CLIENT_PERF_REPORT) and compositor render time (--compositor-report=log)? And the CPU usage when skipping is happening...

This is starting to sound like a duplicate of bug 1377872.

[Daniel van Vugt (vanvugt)]

kdub: Can you provide the following?...

1. GPU type
2. OS version
3. How many displays plugged in? (even if off)

[Kevin DuBois (kdub)]

1) Intel GMA4500HD
2) Ubuntu Vivid with mesa 10.5.0-rc2-0ubuntu1
3) just the primary display

[Kevin DuBois (kdub)]

sampling from the client perf report:
[1426594388.388305] perf: .mir_demo_client_eglplasma-uninstalled: 30.03 FPS, render time 0.16ms, buffer lag 66.43ms (2 buffers)
[1426594389.420548] perf: .mir_demo_client_eglplasma-uninstalled: 30.03 FPS, render time 0.14ms, buffer lag 66.44ms (2 buffers)
[1426594390.452726] perf: .mir_demo_client_eglplasma-uninstalled: 30.03 FPS, render time 0.16ms, buffer lag 66.43ms (2 buffers)
[1426594391.485014] perf: .mir_demo_client_eglplasma-uninstalled: 30.03 FPS, render time 0.16ms, buffer lag 66.42ms (2 buffers)

CPU usage from top (pretty constant from 1-3% on all 3 processes, occasional spikes of up to 6% in the nested server):
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
30046 kdub 20 0 665968 26992 18000 S 2.0 1.4 0:02.38 .mir_demo_serve
30038 root 20 0 579280 23324 16552 S 1.3 1.2 0:01.51 .mir_demo_serve
30065 kdub 20 0 269792 17244 11996 S 1.0 0.9 0:00.91 .mir_demo_clien

[Daniel van Vugt (vanvugt)]

Cool, thanks. There's the smoking gun:

30 FPS while the client render time is 0.16ms. And 66ms to cycle through only two buffers.

I assume on the server side that the render time from --compositor-report=log is zero, because it's in fullscreen bypass (right?).

So this means the driver is misbehaving, as intel does. Check out the workarounds I listed in the other bug.