Performance / Latency problems since the week of Oct 22

[dpkay]

About 10 days ago we started noticing a significantly increased number of frame drops and higher overall latency in our OpenGL application: frames often end up being delayed by 1 frame, either in one or both eyes. The latter is easy to detect since the chaperone and the app image are not aligned anymore and they "swim" with respect to each other.

Have there been any significant changes in the SteamVR runtime (in particular around OpenGL frame submission) around that time? Is there a way to go back to earlier versions to binary-search across runtime versions which version introduced the problem?

We tried running old binaries of our app, and they now exhibit the same issue, which leads us to think that this is caused by a SteamVR upgrade.

[zalo]

If you right click SteamVR from the Tools tab, you can go to the "BETAS" tab and switch your SteamVR version to the previous build, or an even older build than that.

[aaron.leiby]

Are you using an nvidia gpu? There is a shared texture bug that was introduced between version 353 and 355 which sometimes causes the shared mutex fences to fail and would explain what you are seeing. You can see this if you take a gpuview capture.

Separately, I've also been seeing severe performance issues with the extension we are using to share textures between d3d and opengl, though I don't know when those were introduced, or if it just went unnoticed since the beginning of its usage. (wglDXLockObjectsNV and wglDXUnlockObjectsNV) These also use the shared mutex internally I believe, so it's possible this was introduced the same time the above bug was.

[dpkay]

Thanks Aaron.
We are using nvidia GPUs, but my driver is still at 352.86.

What pattern would I look for in gpuview to detect the driver bug you are describing?

[aaron.leiby]

Originally posted by dominik.kaeser:

What pattern would I look for in gpuview to detect the driver bug you are describing?

Lack of fences (pink bars in gpuview) around both vrcompositor.exe and your app's gpu work.

[dpkay]

We think we figured out the problem.

TL;DR: We think that the IVRCompositor::Submit should either have a big warning in the header file advising callers to call glFlush right afterwards, or it should perhaps just trigger a glFlush by itself before returning.

Here are the two symptoms we were observing:
1. In complex scenes of our app (many draw calls), our rendering was often behind by 1 or 2 frames compared to the Chaperone. We did not drop any frames, though.
2. In simple scenes (few draw calls), it looked like we suddenly started to drop *more* frames: the rendered app in the HMD was very juddery, and we saw multiple copies of the chaperone.

We now believe we know what happened:

In case (1), our app nearly filled the OpenGL command buffer in every frame, but not quite enough to trigger a flush. The IVRCompositor::Submit call at the end of the frame added a glCopyImageSubData call to the context queue but still did not trigger a flush. Sometime during the next frame, though, one of our draw calls pushed the context queue over the edge, and finally all the enqueued GL calls (draws from the previous frame, submit and some draws from the current frame) got executed by the GPU. By the time the GPU executed the IVRCompositor’s glCopyTexSubImage call, we missed VSync and thus the frame arrived delayed in the compositor.

In case (2), our frames were so lean that they did not even come close to filling the OpenGL command buffer. As a result, the draw and submit calls of several frames got batched up. Finally, after 4-5 frames when our command buffer was finally full, the GPU executed them. During those 4-5 frames, the compositor did not get any new frames from the app and hence did not draw any new app content (nor did it do a Clear). It did, however, draw the chaperone with a new pose in every frame. Since the compositor did not clear old frames, we saw outdated app content and several versions (poses) of the chaperone rendered all on top of each other. Seeing multiple copies of the same stuff on-screen suspiciously looked like what we would usually see when we drop frames: in those cases, the HMD low-persistence display flashes multiple times with the same framebuffer content. Since the head pose in the real world does not match the outdated head pose in the framebuffer, we perceive them as double-images.

Turns out that in real-life we were often ping-ponging between case (1) and (2) since we sometimes have high-LOD and sometimes low-LOD scenes. As a result, we thought we have both performance and latency problems.

I don’t know why this only became a problem 10 days ago, but this can probably be caused by all kinds of subtle changes in SteamVR and/or the graphics driver, so I am not too worried about it.

(Note, this is still with the 352.86 driver -- I have not tried upgrading yet.)

Thanks for the help!

[artoowang]

We also found a way to reproduce this problem on hellovr_opengl example by commenting out the SDL_GL_SwapWindow() at https://github.com/ValveSoftware/openvr/blob/master/samples/hellovr_opengl/hellovr_opengl_main.cpp#L733

With no swap, the rendered content is not displayed on the desktop window, but is still sent to the compositor. However, without a proper signal (glFlush, glFinish, or swap buffer) to the driver, it seems the driver holds back the commands and only composites the frame several frames late - just like the case (2) above.

[aaron.leiby]

I somehow missed these later posts to this thread. I'll add a glFlush inside the OpenGL path for Submit. On the D3D side, we do a flush in the compositor itself right before Present.


UPDATE:
Looking into this a little more, I think it makes more sense for the app to call glFlush, as they are in a better position to know when best to do this. I would be adding it inside of Submit which gets called twice per frame. I will add a note to the header though.

I was unable to reproduce this via hellovr fwiw.

[phr00t]

Adding glFlush after my submit calls didn't seem to have any effect. What is interesting to note, in the OpenGL "hello cubes" demo, there is a "HACKHACK" that says:

https://github.com/ValveSoftware/openvr/blob/master/samples/hellovr_opengl/hellovr_opengl_main.cpp#L724

From gpuview profiling, it looks like there is a bug where two renders and a present
// happen right before and after the vsync causing all kinds of jittering issues. This glFinish()
// appears to clear that up. Temporary fix while I try to get nvidia to investigate this problem.

Old comment (1/29/2014), but sounds very related. The glFinish isn't a pretty fix (even if it may work), since it must be causing a delay itself (since isn't glFinish a blocking call)?

[hoesing]

I was having some pretty severe judder issues recently. I finally narrowed it down to us not calling VR_Shutdown(). If you fail to call that, the compositor seems to get into a bad state. So the first run would be fine, but subsequent runs in the same compositor session would have severe judder.