SteamVR/Frame Timing

From Valve Developer Community
< SteamVR
Revision as of 21:46, 1 July 2016 by Aleiby (talk | contribs)

Jump to: navigation, search

To display the frame timing graph, right-click on the SteamVR status window and select Settings.

SteamVR Status.PNG


Then click on Performance, find the Display Frame Timing button and click it.

File:FrameTiming Button.png


The default view splits out cpu and gpu performance in a pair of stacked graphs:

File:FrameTiming Stacked.PNG


The blue sections are time spent by the application; these are further split between 'scene' and 'other'. The 'scene' portion is the amount of work performed between when WaitGetPoses returns, and the second eye texture is Submitted (https://github.com/ValveSoftware/openvr/wiki/IVRCompositor_Overview), while 'other' is any time spent after this for rendering the application's companion window, etc. The cpu timing here does not capture any parallel work being performed (e.g. on your application's main thread). The brown 'Other' section in the gpu timing reflects any gpu bubbles, context switching overhead, or gpu work from other application getting scheduled in between other segments of work for that frame. To examine this in more detail require use of gpuview (https://developer.valvesoftware.com/wiki/SteamVR/Installing_GPUView).


Clicking 'Show in Headset' will display this graph in VR as well. This will show up on the back side of your right controller (or at the origin if no controllers are attached). You'll notice the green gpu band take a bit more time when this graph is visible in VR, as rendering Overlays incurs additional work by the compositor.

FrameTiming InHeadset.png


Clicking 'Details' shows a breakdown of all the individual timing being tracked.

File:FrameTiming Details.PNG


This is the same data returned by IVRCompositor.GetFrameTiming.

/** Provides a single frame's timing information to the app */
struct Compositor_FrameTiming
{
	uint32_t m_nSize; // Set to sizeof( Compositor_FrameTiming )
	uint32_t m_nFrameIndex;
	uint32_t m_nNumFramePresents; // number of times this frame was presented
	uint32_t m_nNumDroppedFrames; // number of additional times previous frame was scanned out
	uint32_t m_nReprojectionFlags;

	/** Absolute time reference for comparing frames.  This aligns with the vsync that running start is relative to. */
	double m_flSystemTimeInSeconds;

	/** These times may include work from other processes due to OS scheduling.
	* The fewer packets of work these are broken up into, the less likely this will happen.
	* GPU work can be broken up by calling Flush.  This can sometimes be useful to get the GPU started
	* processing that work earlier in the frame. */
	float m_flPreSubmitGpuMs; // time spent rendering the scene (gpu work submitted between WaitGetPoses and second Submit)
	float m_flPostSubmitGpuMs; // additional time spent rendering by application (e.g. companion window)
	float m_flTotalRenderGpuMs; // time between work submitted immediately after present (ideally vsync) until the end of compositor submitted work
	float m_flCompositorRenderGpuMs; // time spend performing distortion correction, rendering chaperone, overlays, etc.
	float m_flCompositorRenderCpuMs; // time spent on cpu submitting the above work for this frame
	float m_flCompositorIdleCpuMs; // time spent waiting for running start (application could have used this much more time)

	/** Miscellaneous measured intervals. */
	float m_flClientFrameIntervalMs; // time between calls to WaitGetPoses
	float m_flPresentCallCpuMs; // time blocked on call to present (usually 0.0, but can go long)
	float m_flWaitForPresentCpuMs; // time spent spin-waiting for frame index to change (not near-zero indicates wait object failure)
	float m_flSubmitFrameMs; // time spent in IVRCompositor::Submit (not near-zero indicates driver issue)

	/** The following are all relative to this frame's SystemTimeInSeconds */
	float m_flWaitGetPosesCalledMs;
	float m_flNewPosesReadyMs;
	float m_flNewFrameReadyMs; // second call to IVRCompositor::Submit
	float m_flCompositorUpdateStartMs;
	float m_flCompositorUpdateEndMs;
	float m_flCompositorRenderStartMs;

	vr::TrackedDevicePose_t m_HmdPose; // pose used by app to render this frame
};


Use the checkbox next to each label to filter the data. The slider allows you to zoom in and out. When zoomed in far enough, the stacked view will change to a bar graph, which is useful for seeing individual frame timings.

File:FrameTiming Bars.PNG


A red line is drawn when interleaved reprojection kicks in. This line represents the threshold required to be below for three consecutive frames before deactivating.

FrameTiming Reprojection.PNG


In the details view, you can see the 'running start' interval (indicate here by the black 'New Poses Ready' line) has jumped from the standard 3ms, to almost a full frame to give the application more time to render.

FrameTiming ReprojectionDetails.PNG


If you see something that doesn't make sense, post about it on the forums.