harperhendee Posted March 21, 2017 Share Posted March 21, 2017 Seems like many users have encountered an error where one of the controllers is lost and powers down. I have some interesting data on the issue. First off, I'm playing with virtual machines. When I hook my Vive into my steambox, no loss of controller. When I hook the Vive into a VM via my PCIE USB card, I get a high rate of drops. When I route it through one of my on-board USB controllers, I get a lower rate of drops. Here's a typical drop in vrserver.txt Mon Mar 20 2017 21:52:32.161 - Sending InputFocusCaptured old=0 new=8884 Mon Mar 20 2017 21:52:34.478 - Releasing input focus for vrcompositor (8884) because of message. new focus is 0. Mon Mar 20 2017 21:52:34.478 - Sending VREvent_InputFocusReleased old=8884 new=0 Mon Mar 20 2017 21:52:35.527 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.563200ms Mon Mar 20 2017 21:53:19.862 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.854019ms Mon Mar 20 2017 21:56:25.013 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.506210ms Mon Mar 20 2017 21:56:25.303 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.519898ms Mon Mar 20 2017 21:56:25.482 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.607340ms Mon Mar 20 2017 21:56:29.278 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.571581ms Mon Mar 20 2017 21:56:30.609 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.697575ms Mon Mar 20 2017 21:56:30.707 - 4 - entering standby Mon Mar 20 2017 21:56:30.707 - lighthouse: Device LHR-FFA49F41 powering off upon entering standby. Mon Mar 20 2017 21:56:30.708 - 4 - leaving standby Mon Mar 20 2017 21:56:31.395 - lighthouse: 8B14732891: Wireless controller disconnected Mon Mar 20 2017 21:56:31.395 - lighthouse: LHR-FFA49F41: Disconnected from receiver 8B14732891 Mon Mar 20 2017 21:56:31.395 - lighthouse: LHR-FFA49F41 C: Dropped 2566 back-facing hits during the previous tracking session Mon Mar 20 2017 21:56:33.968 - Capturing input focus for vrcompositor (8884). Old focus was 0. Focus stack size 0 Mon Mar 20 2017 21:56:33.968 - Sending InputFocusCaptured old=0 new=8884 Mon Mar 20 2017 21:57:00.038 - lighthouse: LHR-FFA49F41: Connected to receiver 8B14732891 Mon Mar 20 2017 21:57:00.192 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 1.974553ms Mon Mar 20 2017 21:57:00.524 - lighthouse: LHR-FFA49F41 C: basestation transmission profile (ootx) selected, max basestations: 2 Mon Mar 20 2017 21:57:00.647 - lighthouse: LHR-FFA49F41 C: tdm sync acquired From what I can tell, the key ingredient is latency. When I run it on a VM, the latency is greater to service the SendOnPoseChange, and I get more controller drops. It looks like 2 consecutive SendOnPoseChanges that take longer than .5ms within a second will do it. Is it possible to tune the timeout value that SendOnPoseChanges is sensitive to? I think a value of 2ms would mean I never lost the controller. Link to comment Share on other sites More sharing options...
harperhendee Posted March 21, 2017 Author Share Posted March 21, 2017 Here is a link to all my log files: https://drive.google.com/file/d/0B7ky_0GX-JUBUjBnTTAzUDBJUjg/view?usp=sharing Link to comment Share on other sites More sharing options...
Synthesis Posted March 21, 2017 Share Posted March 21, 2017 That's a pretty cool set up you're working on! Currently, SteamVR is designed to run locally and isn't optimized for use through a VM. However, you might be interested to know that at VMWorld 2016, Nvidia showed off their GRID technology in partnership with VMware, so large scale VR on VM is something that's on the horizon. Thanks! -John C Link to comment Share on other sites More sharing options...
harperhendee Posted March 21, 2017 Author Share Posted March 21, 2017 I have read other users who had similar problems with controllers powering off unexpectedly. I think the root cause is this timeout. The "disable power management" button seems like it is focused directly on this issue. But it is really hard to see if it is doing anything at all. It is a single-event button instead of a radio button. Clicking the button doesn't appear to change any configuration file. Where can I find more technical data? Do I need to join a developer program? I'm looking for low level information so that I can make my system work. Right now the oculus system works just fine via PCI passthru, but the Vive is constantly dropping the controller. Here's a outline of the system: Link to comment Share on other sites More sharing options...
Synthesis Posted March 22, 2017 Share Posted March 22, 2017 That's quite the rig you've got there! Let me look into this tomorrow and see if there is some sort of developer group that would be able to better help you with this. Thanks,-John C Link to comment Share on other sites More sharing options...
Jad Posted March 22, 2017 Share Posted March 22, 2017 There was a SteamVR beta update today (1490145859) that provided further fixes for controllers turning off while in use. Opt into the beta and give it a try. Link to comment Share on other sites More sharing options...
Synthesis Posted March 22, 2017 Share Posted March 22, 2017 Great! Let us know! Link to comment Share on other sites More sharing options...
harperhendee Posted March 22, 2017 Author Share Posted March 22, 2017 This beta patch totally fixed the problem. I played through an entire Audioshield session with no loss of controllers. The logs show a number of extra long SendOnPoseChange events, but never drops the controller. I'm not sure if I ever felt the effect of loss of tracking during these multi-milisecond hangs. There were a couple of times I thought I should have been catching a ball but didn't get haptic feedback. Not sure if there was a tracking error with the controller or the Controller (me). A new problem cropped up on this patch though. Gunjack has always complained about unsupported controllers, but then given me perfectly usable controls in game (even if the controllers aren't rendered). When I switched to the beta, Gunjack stopped recognizing any input from the controllers, even though I was able to interact with the dashboard just fine. Here's a snippet of the log showing the unusually long SendOnPoseChange eventts: Wed Mar 22 2017 05:30:59.627 - Unsetting system.generated.audioshield.exe PID because SetApplicationPid came in with a different key Wed Mar 22 2017 05:30:59.627 - Setting app steam.app.412740 PID to 13280 Wed Mar 22 2017 05:30:59.627 - Using existing HMD lighthouse.LHR-0D3CA9A9 Wed Mar 22 2017 05:31:05.454 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.895086ms Wed Mar 22 2017 05:31:05.456 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.685562ms Wed Mar 22 2017 05:31:33.765 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 6.296331ms Wed Mar 22 2017 05:31:33.765 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 3.442058ms Wed Mar 22 2017 05:31:33.765 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 5.808559ms Wed Mar 22 2017 05:31:51.468 - AppTransition: Aborting external launch because of timeout after 0.0019989 seconds Wed Mar 22 2017 05:31:51.468 - Aborting launch of 'steam.app.412740' Wed Mar 22 2017 05:31:51.499 - Capturing input focus for vrcompositor (5908). Old focus was 0. Focus stack size 0 Wed Mar 22 2017 05:31:51.499 - Sending InputFocusCaptured old=0 new=5908 Wed Mar 22 2017 05:31:53.625 - Releasing input focus for vrcompositor (5908) because of message. new focus is 0. Wed Mar 22 2017 05:31:53.625 - Sending VREvent_InputFocusReleased old=5908 new=0 Wed Mar 22 2017 05:31:56.335 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.529956ms Wed Mar 22 2017 05:31:56.335 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.540292ms Wed Mar 22 2017 05:32:04.861 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.570464ms Wed Mar 22 2017 05:32:04.861 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.521295ms Wed Mar 22 2017 05:32:16.568 - lighthouse: LHR-F766BF45 C: SendOnPoseChange took 0.566832ms Wed Mar 22 2017 05:32:16.568 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.567111ms Wed Mar 22 2017 05:32:16.568 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.598121ms Wed Mar 22 2017 05:32:41.989 - lighthouse: LHR-0D3CA9A9 H: SendOnPoseChange took 0.502857ms Wed Mar 22 2017 05:32:41.989 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.522971ms Wed Mar 22 2017 05:33:17.599 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.533308ms Wed Mar 22 2017 05:33:44.476 - lighthouse: LHR-FFA49F41 C: SendOnPoseChange took 0.529397ms I notice that the longest delays are associated with all three endpoints. This would indicate an upstream problem with either USB signal integrity, PCI bridging, KVM hosting, or the XHCI driver. Link to comment Share on other sites More sharing options...
Recommended Posts
Archived
This topic is now archived and is closed to further replies.