Search Unity

Resolved EarlyUpdate.XRUpdate taking about 75% of main thread cpu time. Is this normal?

Discussion in 'AR/VR (XR) Discussion' started by colinleet, Jun 26, 2020.

Thread Status:
Not open for further replies.
  1. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    For the past couple months I've been having a very weird issue with the XR Plugin Management (3.2.10) when using the Oculus XR Plugin (1.3.4) in 2019.4.1f1 (and every stable build since May 2020), wherein the EarlyUpdate.XRUpdate has been take up around 75% of the main thread's CPU time for no apparent reason.

    This is happening for me even with empty projects with just a basic XR Rig.

    Dose anyone have any clue as to what's happening with this call? It's not actively causing me any errors... but it's like ominously ticking black box, which I can't look into, and it is bombing my project with bad performance.

    All that I can find anywhere about EarlyUpdate.XRUpdate is a singe line from the documentation: ("Native engine system updated by the native player loop.") From:
    https://docs.unity3d.com/2019.3/Documentation/ScriptReference/PlayerLoop.EarlyUpdate.XRUpdate.html

    (View photos for timing details.)
    In standalone it's taking around 8 ms of execution time (out of my budgeted 11 ms for 90 HZ). In standalone the execution time for the EarlyUpdate seems to be trying to lock the timing of each frame to fill out the full 11 ms between frames, which is fine... basically it's acting like a non-optional VSync which I can't turn off. Is this guess at all accurate for why it's taking so long? Is it waiting for a callback from the Oculus app with the new frame's headset and controller info?

    Standalone.JPG

    What confuses me most about this is that in-editor it's taking around 3 ms. It's bizarre to me that it would be over 2.5x faster with profiling on in-editor. Also I can't for the life of me figure out why it is giving still be giving me a horrible 3 ms execution time in editor; when the editor loop itself is just as long as an entire 11 ms VR frame, which should mean that there are at least two frames worth of VR input data for every in-editor update call (no need to wait the 3 ms).... What am I missing here?

    EditorTimings1.JPG
    EditorTimings2.JPG

    The problem isn't too much of an issues for me at this point as I use just a couple MS for both scripting + rendering my project with HDRP at this point, but having 75% of my CPU budget going just to XR's under-the-hood/no-peaking-at-what-its-doing-with-deep-profiling mystery update call is driving me crazy and I'm a bit afraid that it's going to put me under impossible timing restrictions of just have 2-3 ms to do all of my scripting and rendering work in the next couple moths as I start to develop the visuals for my game.
     
    Last edited: Oct 7, 2020
    Aldeminor, AldeRoberge and ROBYER1 like this.
  2. turdann

    turdann

    Joined:
    Dec 29, 2012
    Posts:
    43
    Hi @colinleet
    I have the same problem. Did you solve it?
     
    Last edited: Jun 30, 2020
    ImpossibleRobert likes this.
  3. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    Nope. I'm still completely stumped by this, do you think we should report it as a bug? It's just SO BAD. Yet it doesn't seem to have any reasonable explanation that I can fathom, and it technically isn't producing any unexpected behavior other than being slow as hell. Turning off XR entirely makes the problem go away (of course), but I can only do that for short programming testing stents. My game's core design is exclusively VR. I'm tempted to see if this persists with OpenVR to see if it's just a platform dependent bug, as OpenVR can still be used on Oculus, but I want to keep support for Oculus natively as well. Have you tried it with OpenVR or any other XR platforms?
     
    Last edited: Oct 7, 2020
  4. mutp

    mutp

    Joined:
    Oct 1, 2018
    Posts:
    79
    I'm facing the same issue. Completely stumped by this.
     
  5. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    This bug is still driving me crazy. I found that upgrading to the most recent version of XR Plugin Management (3.2.13) made the editor behavior match what I'm seeing in builds much more closely in regards to extending the frames runtime to be 11.2 Ms (90 hz)... Adding more slower code to bulk up my project does seem to lower XREarlyUpdate's runtime (maintaining 90 hz)... I'm still occasionally seeing it take 8-9 Ms in some random frames though (especially in editor)...
     
  6. Clavus

    Clavus

    Joined:
    Jun 6, 2014
    Posts:
    62
    Came to this forum to see about this exact issue. Is there a report for it on the bugtracker yet? Since we should probably make one. Even in a bare minimum scene the EarlyUpdate.XRUpdate takes up 7 to 11ms in-editor according to the profiler.

    EDIT: the XRUpdate might actually just be spinning to keep the fps equal to the headset screen refreshrate in normal operation, but the fact remains is that it's 'overshooting' and lowering the framerate way below the refreshrate right now in-editor.
     
    Last edited: Jul 9, 2020
    colinleet and MartinTilo like this.
  7. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    Just throwing another voice into the ring to say I have the same problem. Unity 2019.4.1f1, using XR Plugin Management 3.2.13 and Oculus XR Plugin preview.2 - 1.4.0 (also had the same issue when on the Verified 1.3.4).

    It straight up sucks when you see that if a bug like this were only HALF as bad, I'd be able to hit my performance threshold (rn a frame takes on average 16-17ms if you include this bug), big oof. I average about 10-11ms waiting on EarlyUpdate.XRUpdate, in editor (haven't tested a build recently, as my builds take a HOT second since this is a big project), and from the sounds of it it'd be the same in a build.
     
  8. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    I can say I know this isn't normal (or shouldn't be), as with the old XR implementation, your CPU in an empty project would only be hit with 1-2ms dedicated to the VR calculations. But I'd also say that's a given considering there's no way they'd expect developers to make large scale VR games with only an 11.1ms budget and they use up 8-10 of those ms :confused:
     
  9. mutp

    mutp

    Joined:
    Oct 1, 2018
    Posts:
    79
    Would it be possible for one of you to file a bug report and attach the case number here? I don't have access to my headset at the moment.
     
    ROBYER1 likes this.
  10. ROBYER1

    ROBYER1

    Joined:
    Oct 9, 2015
    Posts:
    1,454
    It is crucial to report these issues with Unity Bug Reporter - Link here because that way it goes straight to QA and straight to the developers, if you post on the forum, they won't have the information you send over in a bug report such as a reproducible project. If this happens in any empty project it will be very quick to reproduce in a new empty project as a bug report to send over.

    Please post your case number back here too and if they give you a link to Unity Issuetracker so we can all vote on it too!
     
    a436t4ataf likes this.
  11. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    I'll take point on this and make a bug report tomorrow. Mostly why I made this post first is so I could get input from other people to determine if this was even a bug, if it was a larger issue, and what I would even be reporting other than "there is a mystery slow ass function in my random project I can't find anything about".

    Thank you for this update, the idea of overshooting didn't occur to me and explains the problem we're all seeing almost perfectly (especially with it being so random and overshooting more with more complex scenes in editor). I'll use that description as the center of my bug report once I get a shareable bug demo project made.

    Unrelated tip: If you don't already know, closing the scene view often cuts the time of the editor loop in half (from my expense) and can often double my framerate in game... It ain't a good or permanent fix but it's quick and easy when you need it...
     
    ROBYER1 and mutp like this.
  12. Clavus

    Clavus

    Joined:
    Jun 6, 2014
    Posts:
    62
    Let us know when you've set up the report, and link it if possible.
     
    ROBYER1 likes this.
  13. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    I've submitted the bug report and will post the up voting page once I am emailed a link to it...

    Here are a few screenshots I included with the error demo project I submitted....
    Editor Profiler Good Frame Outlier.JPG Editor Profiler Scene View Hidden Overshooting.JPG Editor Profiler Typical Terrible Frame.JPG In Build Overshooting Every Frame.JPG
     
    Aldeminor and ROBYER1 like this.
  14. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
    Thanks for submitting that bug report. Will upvote when you post the link.
     
    ImpossibleRobert likes this.
  15. ImpossibleRobert

    ImpossibleRobert

    Joined:
    Oct 10, 2013
    Posts:
    531
    Do you have the voting page already? This bug is completely driving me crazy. My game was working wonderfully and super smooth with the old integrated VR and since I switched to the XR Plugin multiple things are just a mess (massive performance drop, right eye not rendering correctly anymore...). What in the world is Unity doing in this transition. It seems like the "old" team was let go and the new team looked at the existing code and thought "oh what the hell, why is this here, don't know, let's remove this weird optimization and see if somebody shouts". A pattern I'm just too familiar when code gets handed over. Let's start all from scratch again :-/

    @LeonhardP would be great if you had the VR fixes on the radar, as I am certain you already have but just to make sure :)
     
  16. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
    Pretty typical of Unity ;)
     
  17. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    I have still not heard anything back from the unity team... 9 days out and all my report says is that it's "open" as of a few hours after I submitted the bug report on July 12th...

    If anyone is interested in submitting a new big report I can post a link to the demo project I made, and you could check it out to see if it errors for you as well. Let me know if you would like that link. My error report was long and a bit rambling, they might react faster to something more concise... Or if multiple people start sending in similar reports...
     
  18. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
    @colinleet can you post your project and I'll verify that it acts the same way on my rig.
    I'm grabbing 2020.1 and I'll look a the profiler and see if any improvements are present (doubtful?). I might submit a bug report on that newest release as well.
     
    colinleet likes this.
  19. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    @Autarkis Here is a git repository with my demo scene (GPL-3):
    https://github.com/colinleet/Unity-Slow-XREarlyUpdate-Bug-Repository

    A more up to date demo report in 2020.1 would probably be a great idea. I believe I'm seeing the same but in 2020.1 as well... maybe with slightly better performance but I'm not sure.
     
  20. Katerpilet

    Katerpilet

    Joined:
    Aug 2, 2015
    Posts:
    87
    I also am experiencing this bug. It's worth noting that this also affects the Quest as it tries to do similar frame timing predictions
     
  21. ColtonKadlecik_VitruviusVR

    ColtonKadlecik_VitruviusVR

    Joined:
    Nov 27, 2015
    Posts:
    197
    @colinleet any word on the bug case number?

    EDIT: I agree with @Clavus, I believe the early xr update is just there to maintain the Oculus FPS
     
    Last edited: Sep 2, 2020
  22. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    @ColtonKadlecik_VitruviusV
    I finally got a response after a month in mid August, they couldn't reproduce the behavior and requested some videos of the bug happening. I sent them them three videos about a week later and added a webcam feed to simulate irregular frame timing (along with moving to 2020.1). The updated code is on the repo I posted above. I haven't heard anything back in the last two weeks since then. I can post my videos here if anyone is interested -- if so let me know here.
     
    Aldeminor likes this.
  23. FishStickies94

    FishStickies94

    Joined:
    Jul 27, 2019
    Posts:
    70
    So this still hasn't be answered? I'm also getting high CPU usage and there no answers anywhere.
     
  24. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    We haven't gotten an answer/fix yet as far as I'm aware. And @colinleet if you could share the videos that'd be awesome, just for us to validate that yes we are having the same problem indeed.
     
  25. Clavus

    Clavus

    Joined:
    Jun 6, 2014
    Posts:
    62
    My performance problems were largely resolved after Oculus released v19 of their utilities plugin, which fixed a big performance regression with Rift S users in the editor.
     
  26. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    Are you referring to version 19 of the Oculus Integration asset from the asset store, @Clavus? As the performance problems I and others in this thread have been describing is a part of the Unity XR Plugin Management. I personally don't even have the Oculus Integration installed, only the Oculus XR Plugin from the Package Manager.
     
    AldeRoberge likes this.
  27. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
    Yeah, this is an XR specific bug.
    I've been pulled away working on in game content and I'll re-grab the repo Colin linked to and report a bug case on it this weekend. I'm getting back into testing builds ;)
     
  28. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    @Clavus Yes I made this thread only in reference to XRManagement Plugin not the old Oculus SDK.

    @Autarkis @ExodusOTH
    Here is the bulk of the message I sent back three weeks ago:

    "There were a number of changes in behaviour I've been seeing since switching to 2020.1:

    1) Basically the early update call now is usually around 1 full vr frame instead of 2 ... most of the time.

    2) The performance issues are much more apparent when there is inconsistent code which runs periodically (slow code every few frames).

    This gives the xrEarlyUpdate call a hard time figuring out what it's timing should be, and causes it to wait a very large amount of time for most frames (8-12 ms on average, spiking sometimes to around 20 ms). To simulate this I added a script to render my webcam within the scene, since it adds around a 3 ms script call that is called about every 3rd VR frame. (30 fps vs 90 fps).

    3) The issue is much much more apparent in the editor when the scene view is open.

    4) The bug only shows in standalone when I have a webcam running in the build (simulating inconsistent frame timings).

    My updated version (with the webcam) of the test scene can be pulled from here:
    https://github.com/colinleet/Unity-Slow-XREarlyUpdate-Bug-Repository

    The videos show a bunch of combinations of all the test cases above.

    First video is 9 minutes of editor tests, the first 3 minutes is mostly me explaining my computer setup. The last 6 minutes are editor timings.
    https://leet.games/bugs/Unity-Slow-XREarlyUpdate_in_2020.1.2f1_in_Editor_Start_Here.mp4

    External build with no webcam (good performance):
    https://leet.games/bugs/Unity-Slow-...1.2f1_in_Build_No_Webcam_Good_Performance.mp4

    External build with webcam (bad performance):
    https://leet.games/bugs/Unity-Slow-XREarlyUpdate_in_2020.1.2f1_in_Build_with_Webcam_Is_Bad.mp4
    "
    I haven't gotten any updates yet.
     
    Aldeminor likes this.
  29. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
    Interesting that you're seeing no slow perf hit when you don't have a webcam enabled. Havent tried that, i'll get on it this week :)
     
  30. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    It's having an uneven background task which does it (editor/webcam/whatever). It's not "only"with the webcam, a webcam is just an easy to code processing-intensive backgrounds task to generate a repeatable test case with. Hence XREarlyUpdate almost always being a problem in editor.
     
    Autarkis likes this.
  31. jeromeWork

    jeromeWork

    Joined:
    Sep 1, 2015
    Posts:
    429
    Hi @colinleet

    Could you post a link to that ticket you created in the Issue tracker? I can't find it by doing a search for 'EarlyUpdate.XRUpdate'

    I can confirm that I'm getting the exact same problem in 2019.4.9 LTS
     
  32. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    I never received an issue tracker. Just one email response saying that they couldn't find the issue asking for the videos I posted above. No response to the videos yet (a month out).
     
    jeromeWork likes this.
  33. jeromeWork

    jeromeWork

    Joined:
    Sep 1, 2015
    Posts:
    429
    Thanks @colinleet Doesn't bode well. I've submitted my own bug report (essentially duplicating your own) and I'd recommend that anyone with the same issue do the same.

    The more people flag up the issue, the more Unity are likely to take it seriously. It really does make the editor unusable for VR development.
     
  34. Tomana5

    Tomana5

    Unity Technologies

    Joined:
    Jul 16, 2019
    Posts:
    4
  35. jeromeWork

    jeromeWork

    Joined:
    Sep 1, 2015
    Posts:
    429
    Thanks @TomasAnavicius Much appreciated.
    Fingers crossed for a quick fix :)
     
  36. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    Last edited: Oct 1, 2020
  37. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    @Autarkis @ExodusOTH @Clavus @TheMaximL @mutp @turdann @ROBYER1
    @ImpossibleRobert
    @ColtonKadlecik_VitruviusV @Katerpilet

    TLDR: We've got a bug report to upvote!
    https://issuetracker.unity3d.com/product/unity/issues/guid/1262597/

    (* tagging everyone who has commented)

    Long version: Thank you everyone who has commented and helped with this post over the last three months, it has given me major respect for the development community here as a whole. Hearing other confused voices is a seriously bright light in a very long dark tunnel when you've been facing down a undefeatable bug for so long. Last thing for us to do now is just upvote the tracker to the stars.
     
    Last edited: Oct 1, 2020
  38. Autarkis

    Autarkis

    Joined:
    Oct 10, 2011
    Posts:
    318
  39. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    Along the lines of the Bug Report that we have listed, does anybody else experience the EarlyUpdate.XRUpdate WAY overcompensate when trying to "match 11ms"? For example, mine is taking 16ms on a consistent basis (not inconsistent like the bug ticket we have), to bring my total to 22ms. The rest of my game is only taking 6ms.
    upload_2020-10-6_21-47-7.png
     
    Aldeminor likes this.
  40. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    Yes that's the exact conditions I reported about at the start of this thread (see the last photo I posted in this thread). For me it was not 100% constant in editor but with 2019.4/early 2020.1 releases I did have XREarlyUpdate overshoot more than a full VR frame often, especially when the scene view was open. It was more rare in standalone builds.
     
    Last edited: Oct 7, 2020
    Aldeminor likes this.
  41. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    Ah, glad I'm not crazy. I thought when I first joined the thread we were all having the same problem and then when I saw the bug ticket that we could vote on I was like "eh?" but it's good to know it's all connected!
     
  42. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    Do you have the ability to move to the most recent release? I've found this problem to be a lot more stable (10-13ms total in editor with the scene view closed) and in builds recently.
     
  43. ExodusOTH

    ExodusOTH

    Joined:
    Nov 30, 2017
    Posts:
    45
    Those most recent screenshots were after I had just updated to the latest (as of yesterday, October 6, 2020) XR Plugin Management and Oculus XR Plug-in respectively
     
  44. BATTLEKOT

    BATTLEKOT

    Joined:
    Oct 2, 2016
    Posts:
    179
    So that problem caused by XR Manager and Oculus XR? Or this is Unity problem?

    Here is October 26 2020 and its still happening in 2020.1 and 2020.2 with HDRP
     
  45. colinleet

    colinleet

    Joined:
    Nov 20, 2019
    Posts:
    189
    From all of the reports I've seen on this thread it's from Oculus SDK + XR Management. Still no word on a fix.
     
  46. BATTLEKOT

    BATTLEKOT

    Joined:
    Oct 2, 2016
    Posts:
    179
    sad, in any case i pack project and send report bug about that:
    Case 1289293
     
  47. Shaunyowns

    Shaunyowns

    Joined:
    Nov 4, 2019
    Posts:
    328
    Hey there!

    We can confirm that this bug is in our backlog. We will take a look, and share updates via Issue Tracker, thank you everyone!
     
Thread Status:
Not open for further replies.