VR Rendering Performance Questions

John_Alcatraz · May 20, 2016, 10:41pm

I got a few questions regarding VR rendering performance, first, I see a significant difference in the frame time between running a packaged game with -emulatestereo and running it in real VR.

The Scene time is almost 100% identical, 6.46ms with emulatestereo and 6.48ms with real VR, but in VR there is something adding 1.27ms on top of that. What is it? I don’t have any UI in the game, so Slate should not take any time.

Emulatestereo:
[Spoiler]



[2016.05.20-22.04.36:980][666]LogRHI:Warning: Perf marker hierarchy, total GPU time 6.51ms
[2016.05.20-22.04.36:980][666]LogRHI:Warning: Profiled range was continuous.
[2016.05.20-22.04.36:980][666]LogRHI:Warning: 100.0% 6.51ms   FRAME 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning: 99.1% 6.46ms   Scene 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.0% 0.00ms   ClearLPVs 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     1.7% 0.11ms   BeginRenderingSceneColor 1 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:    12.6% 0.82ms   BasePass 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        6.6% 0.43ms   View0 25 draws 110355 prims 214292 verts 258286 prims/ms 501550 verts/ms
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        6.0% 0.39ms   View1 25 draws 110355 prims 214292 verts 282265 prims/ms 548113 verts/ms
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     1.8% 0.12ms   HZB SetupMip 0 1024x1024 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.9% 0.06ms   HZB SetupMips 1..9 512x512 Mips:0 9 draws 9 prims 27 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.6% 0.04ms   HZB SetupMip 0 1024x1024 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.9% 0.06ms   HZB SetupMips 1..9 512x512 Mips:0 9 draws 9 prims 27 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.0% 0.00ms   BeginOcclusionTests 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        0.0% 0.00ms   IndividualQueries 1 draws 12 prims 8 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        0.0% 0.00ms   GroupedQueries 1 draws 12 prims 8 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.0% 0.00ms   BeginOcclusionTests 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        0.0% 0.00ms   IndividualQueries 1 draws 12 prims 8 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        0.0% 0.00ms   GroupedQueries 1 draws 12 prims 8 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     2.8% 0.18ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        2.8% 0.18ms   LightCompositionTasks_PreLighting 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:           2.8% 0.18ms   AmbientOcclusionPS 1120x1260 SetupAsInput=0 Upsample=0 ShaderQuality=0 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     2.5% 0.16ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:        2.5% 0.16ms   LightCompositionTasks_PreLighting 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:           2.5% 0.16ms   AmbientOcclusionPS 1120x1260 SetupAsInput=0 Upsample=0 ShaderQuality=0 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.1% 0.00ms   ClearStencilFromBasePass 1 draws 0 prims 0 verts
[2016.05.20-22.04.36:980][666]LogRHI:Warning:     0.2% 0.01ms   ClearTranslucentVolumeLighting 1 draws 8 prims 16 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    12.8% 0.83ms   Lights 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:       12.8% 0.83ms   DirectLighting 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.0% 0.00ms   NonShadowedLights 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:              0.0% 0.00ms   StandardDeferredLighting 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.0% 0.00ms   IndirectLighting 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:              0.0% 0.00ms   UpdateLPVs 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:          12.8% 0.83ms   ShadowedLights 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:             12.8% 0.83ms   Level.LightSource 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                 0.1% 0.01ms   BeginRenderingLightAttenuation 1 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                 1.0% 0.07ms   ShadowDepthsFromOpaqueProjected 1 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                    0.9% 0.06ms   WholeScene split 0 23 draws 106386 prims 212082 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                 5.7% 0.37ms   ShadowProjectionOnOpaque3 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                    3.5% 0.23ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                       3.5% 0.23ms   WholeScene split 0 4 draws 6 prims 14 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                    2.1% 0.14ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                       2.1% 0.14ms   WholeScene split 0 4 draws 6 prims 14 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                 0.2% 0.01ms   InjectTranslucentVolume 2 draws 16 prims 32 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:                 5.8% 0.38ms   StandardDeferredLighting 2 draws 2 prims 6 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     3.1% 0.20ms   SkyLightDiffuse 2 draws 4 prims 8 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     1.1% 0.07ms   ScreenSpaceReflections 1120x1260 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     2.1% 0.13ms   ReflectionApply 1 draws 2 prims 4 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:        0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     1.7% 0.11ms   ScreenSpaceReflections 1120x1260 3 draws 9 prims 13 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     2.0% 0.13ms   ReflectionApply 1 draws 2 prims 4 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:        0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.0% 0.00ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.0% 0.00ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.8% 0.05ms   ExponentialHeightFog 1120x1260 1 draws 2 prims 4 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.8% 0.05ms   ExponentialHeightFog 1120x1260 1 draws 2 prims 4 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     1.0% 0.07ms   Translucency 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:        0.8% 0.05ms   View0 6 draws 46 prims 92 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:        0.2% 0.02ms   View1 5 draws 46 prims 92 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    49.7% 3.23ms   PostProcessing 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:        9.8% 0.64ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           4.2% 0.27ms   TemporalAA 1120x1260 3 draws 2 prims 6 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.3% 0.02ms   PostProcessEyeAdaptation 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.3% 0.02ms   PostProcessCombineLUTs 32x32x32 1 draws 64 prims 128 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.8% 0.12ms   Tonemapper#3 1120x1260 2 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.9% 0.12ms   PostProcessMaterial 1120x1260 Material=GeneralPPMat 2 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.2% 0.08ms   PostProcessUpscale 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:       39.9% 2.60ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:          34.5% 2.25ms   TemporalAA 1120x1260 3 draws 2 prims 6 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           0.5% 0.03ms   PostProcessCombineLUTs 32x32x32 1 draws 64 prims 128 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.8% 0.12ms   Tonemapper#3 1120x1260 2 draws 2 prims 4 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.8% 0.12ms   PostProcessMaterial 1120x1260 Material=GeneralPPMat 2 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:           1.2% 0.08ms   PostProcessUpscale 1 draws 1 prims 3 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning:     0.0% 0.00ms   RenderFinish 0 draws 0 prims 0 verts
[2016.05.20-22.04.36:981][666]LogRHI:Warning: Total Nodes 124 Draws 156 approx overhead 1.49ms
[2016.05.20-22.04.36:981][666]LogRHI:Warning: 
[2016.05.20-22.04.36:981][666]LogRHI:Warning: 
[2016.05.20-22.04.36:981][666]LogRHI:Warning: Node histogram 43 buckets
[2016.05.20-22.04.36:981][666]LogRHI:Warning:  r.ProfileGPU.Pattern = '*' (using threshold of 5 ms)
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    6.51ms   FRAME   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    6.46ms   Scene   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    3.31ms   View1   Events 6   Draws 30
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    3.23ms   PostProcessing   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    2.52ms   TemporalAA 1120x1260   Events 2   Draws 6
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    1.53ms   View0   Events 6   Draws 31
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.83ms   ShadowedLights   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.83ms   DirectLighting   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.83ms   Lights   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.83ms   Level.LightSource   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.82ms   BasePass   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.43ms   WholeScene split 0   Events 3   Draws 31
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.38ms   StandardDeferredLighting   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.37ms   ShadowProjectionOnOpaque3   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.35ms   AmbientOcclusionPS 1120x1260 SetupAsInput=0 Upsample=0 ShaderQuality=0   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.35ms   LightCompositionTasks_PreLighting   Events 2   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.27ms   ReflectionApply   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.24ms   PostProcessMaterial 1120x1260 Material=GeneralPPMat   Events 2   Draws 4
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.23ms   Tonemapper#3 1120x1260   Events 2   Draws 4
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.20ms   SkyLightDiffuse   Events 1   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.19ms   ScreenSpaceReflections 1120x1260   Events 2   Draws 4
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.16ms   PostProcessUpscale   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.15ms   HZB SetupMip 0 1024x1024   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.12ms   HZB SetupMips 1..9 512x512 Mips:0   Events 2   Draws 18
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.11ms   ExponentialHeightFog 1120x1260   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.11ms   BeginRenderingSceneColor   Events 1   Draws 1
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.07ms   ShadowDepthsFromOpaqueProjected   Events 1   Draws 1
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.07ms   Translucency   Events 1   Draws 0
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    0.06ms   PostProcessCombineLUTs 32x32x32   Events 2   Draws 2
[2016.05.20-22.04.36:981][666]LogRHI:Warning:    Total 31.55ms   Events 54   Draws 146,    14 buckets not shown

[/Spoiler]
Real VR:
[Spoiler]



[2016.05.20-22.03.37:869][142]LogRHI:Warning: Perf marker hierarchy, total GPU time 7.75ms
[2016.05.20-22.03.37:869][142]LogRHI:Warning: Profiled range was continuous.
[2016.05.20-22.03.37:869][142]LogRHI:Warning: 100.0% 7.75ms   FRAME 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning: 83.6% 6.48ms   Scene 2 draws 40 prims 120 verts 6 prims/ms 19 verts/ms
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.1% 0.01ms   BeginRenderingPrePass 1 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.0% 0.00ms   ClearLPVs 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     2.2% 0.17ms   BeginRenderingSceneColor 1 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:    14.1% 1.09ms   BasePass 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        7.2% 0.56ms   View0 24 draws 103603 prims 200788 verts 186485 prims/ms 361418 verts/ms
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        6.9% 0.54ms   View1 24 draws 103603 prims 200788 verts 193557 prims/ms 375123 verts/ms
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     2.3% 0.18ms   HZB SetupMip 0 1024x1024 1 draws 1 prims 3 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.7% 0.06ms   HZB SetupMips 1..9 512x512 Mips:0 9 draws 9 prims 27 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.7% 0.06ms   HZB SetupMip 0 1024x1024 1 draws 1 prims 3 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.7% 0.06ms   HZB SetupMips 1..9 512x512 Mips:0 9 draws 9 prims 27 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.0% 0.00ms   BeginOcclusionTests 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        0.0% 0.00ms   IndividualQueries 1 draws 12 prims 8 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        0.0% 0.00ms   GroupedQueries 1 draws 24 prims 16 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.0% 0.00ms   BeginOcclusionTests 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        0.0% 0.00ms   GroupedQueries 1 draws 24 prims 16 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     4.5% 0.35ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        4.5% 0.35ms   LightCompositionTasks_PreLighting 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:           4.5% 0.35ms   AmbientOcclusionPS 1512x1680 SetupAsInput=0 Upsample=0 ShaderQuality=0 1 draws 1 prims 3 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     3.8% 0.29ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        3.8% 0.29ms   LightCompositionTasks_PreLighting 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:           3.8% 0.29ms   AmbientOcclusionPS 1512x1680 SetupAsInput=0 Upsample=0 ShaderQuality=0 1 draws 1 prims 3 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.1% 0.00ms   ClearStencilFromBasePass 1 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.1% 0.01ms   ClearTranslucentVolumeLighting 1 draws 8 prims 16 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:    16.8% 1.30ms   Lights 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:       16.8% 1.30ms   DirectLighting 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:           0.0% 0.00ms   NonShadowedLights 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:              0.0% 0.00ms   StandardDeferredLighting 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:           0.0% 0.00ms   IndirectLighting 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:              0.0% 0.00ms   UpdateLPVs 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:          16.8% 1.30ms   ShadowedLights 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:             16.8% 1.30ms   Level.LightSource 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                 0.1% 0.01ms   BeginRenderingLightAttenuation 1 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                 0.9% 0.07ms   ShadowDepthsFromOpaqueProjected 1 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                    0.9% 0.07ms   WholeScene split 0 25 draws 115052 prims 229414 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                 8.0% 0.62ms   ShadowProjectionOnOpaque3 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                    5.1% 0.39ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                       5.1% 0.39ms   WholeScene split 0 4 draws 6 prims 14 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                    3.0% 0.23ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                       3.0% 0.23ms   WholeScene split 0 4 draws 6 prims 14 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                 0.1% 0.01ms   InjectTranslucentVolume 2 draws 16 prims 32 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:                 7.6% 0.59ms   StandardDeferredLighting 2 draws 2 prims 6 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     4.0% 0.31ms   SkyLightDiffuse 2 draws 4 prims 8 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     1.3% 0.10ms   ScreenSpaceReflections 1512x1680 1 draws 23 prims 69 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     2.7% 0.21ms   ReflectionApply 1 draws 2 prims 4 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:        0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:869][142]LogRHI:Warning:     2.4% 0.19ms   ScreenSpaceReflections 1512x1680 3 draws 31 prims 79 verts 166 prims/ms 422 verts/ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     2.7% 0.21ms   ReflectionApply 1 draws 2 prims 4 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:        0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     0.0% 0.00ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     0.0% 0.00ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     1.3% 0.10ms   ExponentialHeightFog 1512x1680 1 draws 2 prims 4 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     1.3% 0.10ms   ExponentialHeightFog 1512x1680 1 draws 2 prims 4 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     1.0% 0.08ms   Translucency 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:        0.8% 0.06ms   View0 6 draws 46 prims 92 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:        0.2% 0.02ms   View1 5 draws 46 prims 92 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           0.0% 0.00ms   FinishRenderingSceneColor 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    20.6% 1.60ms   PostProcessing 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:       10.8% 0.84ms   View0 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           5.4% 0.42ms   TemporalAA 1512x1680 3 draws 46 prims 138 verts 110 prims/ms 331 verts/ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           0.3% 0.02ms   PostProcessEyeAdaptation 1 draws 1 prims 3 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           0.3% 0.02ms   PostProcessCombineLUTs 32x32x32 1 draws 64 prims 128 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           2.4% 0.19ms   Tonemapper#3 1512x1680 2 draws 23 prims 69 verts 123 prims/ms 369 verts/ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           2.4% 0.19ms   PostProcessMaterial 1512x1680 Material=GeneralPPMat 1 draws 23 prims 69 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:        9.9% 0.76ms   View1 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           5.0% 0.39ms   TemporalAA 1512x1680 3 draws 46 prims 138 verts 118 prims/ms 354 verts/ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           0.4% 0.03ms   PostProcessCombineLUTs 32x32x32 1 draws 64 prims 128 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           2.4% 0.19ms   Tonemapper#3 1512x1680 2 draws 23 prims 69 verts 121 prims/ms 363 verts/ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning:           2.0% 0.15ms   PostProcessMaterial 1512x1680 Material=GeneralPPMat 1 draws 23 prims 69 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     0.0% 0.00ms   RenderFinish 0 draws 0 prims 0 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:  6.0% 0.46ms   SlateUI 2 draws 2 prims 4 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     0.0% 0.00ms   CanvasFlush 16 draws 376 prims 752 verts
[2016.05.20-22.03.37:870][142]LogRHI:Warning:     5.9% 0.46ms   Other Children
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    10.5% 0.81ms   Other Children
[2016.05.20-22.03.37:870][142]LogRHI:Warning: Total Nodes 125 Draws 172 approx overhead 1.50ms
[2016.05.20-22.03.37:870][142]LogRHI:Warning: 
[2016.05.20-22.03.37:870][142]LogRHI:Warning: 
[2016.05.20-22.03.37:870][142]LogRHI:Warning: Node histogram 45 buckets
[2016.05.20-22.03.37:870][142]LogRHI:Warning:  r.ProfileGPU.Pattern = '*' (using threshold of 5 ms)
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    7.75ms   FRAME   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    6.48ms   Scene   Events 1   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    2.20ms   View0   Events 6   Draws 30
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.84ms   View1   Events 6   Draws 29
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.60ms   PostProcessing   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.30ms   DirectLighting   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.30ms   Lights   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.30ms   ShadowedLights   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.30ms   Level.LightSource   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    1.09ms   BasePass   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.81ms   TemporalAA 1512x1680   Events 2   Draws 6
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.69ms   WholeScene split 0   Events 3   Draws 33
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.64ms   LightCompositionTasks_PreLighting   Events 2   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.64ms   AmbientOcclusionPS 1512x1680 SetupAsInput=0 Upsample=0 ShaderQuality=0   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.62ms   ShadowProjectionOnOpaque3   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.59ms   StandardDeferredLighting   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.46ms   SlateUI   Events 1   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.42ms   ReflectionApply   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.38ms   Tonemapper#3 1512x1680   Events 2   Draws 4
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.34ms   PostProcessMaterial 1512x1680 Material=GeneralPPMat   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.31ms   SkyLightDiffuse   Events 1   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.29ms   ScreenSpaceReflections 1512x1680   Events 2   Draws 4
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.23ms   HZB SetupMip 0 1024x1024   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.20ms   ExponentialHeightFog 1512x1680   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.17ms   BeginRenderingSceneColor   Events 1   Draws 1
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.12ms   HZB SetupMips 1..9 512x512 Mips:0   Events 2   Draws 18
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.08ms   Translucency   Events 1   Draws 0
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.07ms   ShadowDepthsFromOpaqueProjected   Events 1   Draws 1
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    0.05ms   PostProcessCombineLUTs 32x32x32   Events 2   Draws 2
[2016.05.20-22.03.37:870][142]LogRHI:Warning:    Total 33.28ms   Events 53   Draws 146,    16 buckets not shown

[/Spoiler]

Second question, is the way the game thread time, render thread time and GPU time add up differently in VR? I could think of that the amount of frames the game thread or render thread is behind is different in VR. Sometimes I had the feeling the render thread time and GPU time add up in VR to the total frame time, since my GPU time stayed well below 11 ms (let’s say 9 ms) but I still wasn’t able to get 11 ms frame time so the game was capped at 22 ms instead of 11 ms. So does the render thread and GPU run all in one frame without a frame delay on VR to reduce latency? Is it different from how it works without VR?

Now in this example above, my GPU time was 6.46 ms with -emulatestereo. Profiling with stat startfile and stat stopfile and looking at the render thread gave me this:
[Spoiler]

[/Spoiler]
So the render thread time is 4.4 ms, it does not seem to add up with the GPU time for the total frame time since my total frame time equals the GPU time here when I use -emulatestereo. Without emulatestereo I can’t really see the real total frame time since it’s capped at 11 ms.

Regarding the stuff that’s going on in the RT, what is it doing? 2.5 ms for Slate stuff is a really long time since I don’t have any UI in my game at the moment. What is Slate doing here? How can I reduce that time?

The other thing the render thread spends most time with seems to be occlusion. There is exactly 1 Actor in the world with roughly 10 or 15 components, so really not much to cull. Why is it taking 1.1 ms? Looking at the source, FetchVisibilityForPrimitives and RenderQueryResult seems to mostly wait for the GPU to send stuff. What can I do to reduce that time?

Thanks!

mechanicalsnowman · May 23, 2016, 4:38pm

I am not too sure about the rest of it, but it’s possible that Slate in this instance is the mirror to desktop. Try using the command “HMD mirror 0” and then profile again to see if this reduces / eliminates SlateUI.

John_Alcatraz · May 26, 2016, 4:48pm

Will try that, thanks for the suggestion

John_Alcatraz · June 12, 2016, 12:57am

I have tested it with hmd mirror 1 and hmd mirror 0, I get the exact same time with profilegpu, so it does not affect it

I’m on 4.12 now, but I still get that 1.3 ms that are added on top of the GPU time:

[2016.06.12-00.53.06:357][622]LogRHI:Warning: 100.0% 5.27ms FRAME 188 draws 124541 prims 83897 verts
[2016.06.12-00.53.06:357][622]LogRHI:Warning: 75.4% 3.98ms Scene 188 draws 124541 prims 83897 verts 10 prims/ms 30 verts/ms
[2016.06.12-00.53.06:358][622]LogRHI:Warning: 0.0% 0.00ms RenderFinish 0 draws 0 prims 0 verts
[2016.06.12-00.53.06:358][622]LogRHI:Warning: 24.6% 1.30ms Other Children

25% is quite a lot in VR, so any ideas what that is?

John_Alcatraz · June 16, 2016, 11:02am

Any ideas? I hoped anyone from Epic who knows what’s going on might have some answers for my questions :o

John_Alcatraz · July 3, 2016, 3:22pm

Maybe this thread should be moved to the VR section?

John_Alcatraz · July 11, 2016, 5:39pm

Thanks for moving Anyone has any ideas now?

anonymous_user_b255ac231 · July 12, 2016, 6:21am

I’m not technical enough to answer all of your questions but for your one about emulate stereo vs VR, I know when Oculus introduced direct mode for the Rift one of the main benefits was it got rid of the buffering of old frames to reduce latency (at the cost of some perf), I’m not certain whether emulate does this natively but if you want to force UE to finish the frame before it starts on the new one try the r.FinishCurrentFrame=1 console command.

As for the occlusion culling generally Epic disables HZB occlusion culling for all their VR demos as currently it takes up to much time for smaller scenes, you can do this with r.HZBOcclusion=0

Hope that helps

Ironbelly · October 28, 2016, 5:45pm

Setting r.FinishCurrentFrame=1 nearly doubles all of my times when tried…