search

ValveSoftware / steamvr_unreal_plugin

SteamVR Input Unreal Plugin - Documentation at: https://github.com/ValveSoftware/steamvr_unreal_plugin/wiki Sample project (UE4.15-4.23): https://github.com/ValveSoftware/steamvr_unreal_plugin/wiki/sample/SteamVRInputPlugin.zip Sample Project (UE.424+): https://github.com/ValveSoftware/steamvr_unreal_plugin/wiki/sample/SteamVRInputPlugin_UEIntegrated.7z
Other
166 stars 29 forks source link

SteamVR loading resources after level change #175

Closed protowlf closed 3 years ago

protowlf commented 3 years ago

This is partially a question on how this part of the plugin works, partially a concern that SteamVR may be causing issues with async package loading. (I don't compile engine so I unfortunately can't breakpoint this logic myself)

When running package builds, in output logs, SteamVR plugin appears to re-load meshes when changing levels sometimes. I see output like this after calling GameplayStatics;:OpenLevel() (this is not full output just snippets, similar lines repeat many times):

[2021.01.03-01.01.59:600][567]LogLoad: Took 0.145539 seconds to LoadMap(############)
[2021.01.03-01.01.59:639][569]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000243AF53F4B0
[2021.01.03-01.01.59:639][569]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000243AF53EF70
... etc ...
[2021.01.03-01.01.59:647][569]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\body.obj rVertexData 0x1e256010 unVertexCount 5916 rIndexData 0x1e15c470 unTriangleCount 6944 diffuseTextureId 0
[2021.01.03-01.01.59:647][569]LogStreaming: Display: Flushing async loaders.
[2021.01.03-01.01.59:648][569]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 00000243A6423410
[2021.01.03-01.01.59:648][569]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\button_a.obj rVertexData 0xafb59060 unVertexCount 193 rIndexData 0x8799de10 unTriangleCount 240 diffuseTextureId 0
[2021.01.03-01.01.59:648][569]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 00000243A6423410
[2021.01.03-01.01.59:648][569]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\button_b.obj rVertexData 0x1e0ad3d0 unVertexCount 192 rIndexData 0x879999d0 unTriangleCount 240 diffuseTextureId 0
... etc ...

What is the intended behavior? It seems like it tries to cache models, but sometimes ends up loading them again anyways. Not sure if I'm interpreting the output correctly.

My concern is that the SteamVR plugin might be interrupting my async loading when it tries to load its own assets. I'm using async package loading to stream levels in my VR project. Basically I do a LoadPackageAsync() call to load my level asset in the background, then call OpenLevel() for a really quick level change. I actually do this twice in a row, because I asynchronously load my loading-level, open it, then quickly start asynchonously loading my destination level, have the player wait in the loading-level while that loads in the background, and finally open the destination level.

Maybe 1 in 10 level loads, after the loading-level is opened and I quickly start the second asynchronous load, I get a 2 second hitch with the output "LogStreaming: Display: Flushing async loaders." As I understand it, the async package loader will be flushed if a synchronous load occurs mid-way through an asynchronous one. This would cause it to block the game thread while it loads my level synchronously after being interrupted. Given the suspicious steam vr output, my hunch is that steamvr is the thing interrupting my async load.

If my hunch is correct, I can probably work around this by waiting longer between opening a level and starting the next async level load. However the SteamVR plugin output is odd, so I wanted to at least learn what it is doing.

protowlf commented 3 years ago

Here's a longer log isolating the steamvr plugin output after OpenLevel.

This is a development package build, engine version 4.24, on an Index:

[2021.01.03-20.44.39:555][882]LogLoad: Took 0.047325 seconds to LoadMap(#############)
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2CC0
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2780
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2540
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2420
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2B40
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2C30
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2D80
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 00000206242E2AB0
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 000002069B077230
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 000002069B077650
[2021.01.03-20.44.39:626][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Creating new TSharedPtr for resource 0000020668D6B310
[2021.01.03-20.44.39:632][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\body.obj rVertexData 0x9b5ec010 unVertexCount 5916 rIndexData 0x9b636030 unTriangleCount 6944 diffuseTextureId 0
[2021.01.03-20.44.39:633][884]LogStreaming: Display: Flushing async loaders.
[2021.01.03-20.44.39:633][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:633][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\button_a.obj rVertexData 0xfe8950 unVertexCount 193 rIndexData 0xafd033b0 unTriangleCount 240 diffuseTextureId 0
[2021.01.03-20.44.39:633][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:633][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\button_b.obj rVertexData 0x9b26f1c0 unVertexCount 192 rIndexData 0xafd03980 unTriangleCount 240 diffuseTextureId 0
[2021.01.03-20.44.39:634][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:634][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\led_left.obj rVertexData 0x940d30 unVertexCount 54 rIndexData 0x7cfa170 unTriangleCount 52 diffuseTextureId 0
[2021.01.03-20.44.39:634][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:634][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\gripsqueeze.obj rVertexData 0x12a0aa0 unVertexCount 308 rIndexData 0x98f8c200 unTriangleCount 405 diffuseTextureId 0
[2021.01.03-20.44.39:634][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:634][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\button_system.obj rVertexData 0x98fb42b0 unVertexCount 237 rIndexData 0xafd08510 unTriangleCount 240 diffuseTextureId 0
[2021.01.03-20.44.39:634][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:634][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\thumbstick.obj rVertexData 0xa9c3b030 unVertexCount 313 rIndexData 0x9ad9bf30 unTriangleCount 504 diffuseTextureId 0
[2021.01.03-20.44.39:634][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:634][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\trackpad.obj rVertexData 0x9b34c0b0 unVertexCount 289 rIndexData 0x9bb580e0 unTriangleCount 380 diffuseTextureId 0
[2021.01.03-20.44.39:635][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\trackpad_scroll_wheel.obj rVertexData 0x98f995a0 unVertexCount 470 rIndexData 0x98da5f00 unTriangleCount 768 diffuseTextureId 0
[2021.01.03-20.44.39:635][884]LogSteamVR: TSteamVRResourceLoader::WrapResource: Returning existing resource 0000020668D6B310
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModel::GetRawMeshData ResourceId C:\Program Files (x86)\Steam\steamapps\common\SteamVR\drivers\indexcontroller\resources\rendermodels\valve_controller_knu_1_0_left\trigger.obj rVertexData 0x991a5350 unVertexCount 290 rIndexData 0xafd7b020 unTriangleCount 404 diffuseTextureId 0
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRTextureLoader::FreeResource_Internal: Freeing texture resource 0000020668D6B310
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2CC0
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2780
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2540
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2420
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2B40
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2C30
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2D80
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 00000206242E2AB0
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 000002069B077230
[2021.01.03-20.44.39:635][884]LogSteamVR: FSteamVRModelLoader::FreeResource_Internal: Freeing render model instance 000002069B077650

Regarding the hitch on flush async loaders, it seems that if I wait a full second between OpenLevel and running new AsyncPackageLoad() calls, I don't get my hitch. Again, not 100% sure SteamVR plugin is responsible for the hitch, but the output suggests it may be.

1runeberg commented 3 years ago

Hi @drspud - thanks for the report. not exactly sure what's going on there, but this seems something Epic Games should look at in the first instance as the model loader is just an implementation of the engine's overall XR archi so this can be a more general issue. In addition, model loaders and hmd module of the plugin was developed exclusively by Epic so they may be the best to judge root cause and fix accordingly.

I suggest bringing this up directly via their online support resource: https://www.unrealengine.com/en-US/support?sessionInvalidated=true