Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

(Beta 2.2.1) OpenXR call failed with result XR_ERROR_CALL_ORDER_INVALID (Linux) #1804

Open
WhitleyStriber opened this issue Dec 14, 2023 · 1 comment

Comments

@WhitleyStriber
Copy link

I'm currently developing an app on Unreal Engine and receive this error when trying to launch VR preview more than once. I would LOVE to be on Linux to create my game, but this issue makes it impossible for any developer to create games on Linux.

I am able to launch the VR preview once and debug the game just fine in VR, but when I launch it a 2nd time, this callstack and error log gets printed to console:

[2023.12.14-13.05.09:410][968]LogAudioMixerSDL: Opening default audio device (device index -1)
[2023.12.14-13.05.09:411][968]LogAudioMixer: Display: Using Audio Hardware Device USB Audio S/PDIF Output
[2023.12.14-13.05.09:411][968]LogAudioMixer: Display: Initializing Sound Submixes...
[2023.12.14-13.05.09:411][968]LogAudioMixer: Display: Creating Master Submix 'MasterSubmixDefault'
[2023.12.14-13.05.09:411][968]LogAudioMixer: Display: Creating Master Submix 'MasterReverbSubmixDefault'
[2023.12.14-13.05.09:412][968]LogAudioMixer: Display: Output buffers initialized: Frames=1024, Channels=6, Samples=6144, InstanceID=3
[2023.12.14-13.05.09:412][968]LogAudioMixer: Display: Starting AudioMixerPlatformInterface::RunInternal(), InstanceID=3
[2023.12.14-13.05.09:412][968]LogInit: FAudioDevice initialized with ID 3.
[2023.12.14-13.05.09:412][968]LogAudio: Display: Audio Device (ID: 3) registered with world 'VRTemplateMap'.
[2023.12.14-13.05.09:412][968]LogAudioMixer: Initializing Audio Bus Subsystem for audio device with ID 3
[2023.12.14-13.05.09:434][968]LogSlate: Updating window title bar state: overlay mode, drag disabled, window buttons hidden, title bar hidden
Ensure condition failed: ((Result) >= 0) [File:./../Plugins/Runtime/OpenXR/Source/OpenXRHMD/Private/OpenXRHMD.cpp] [Line: 1787] 
OpenXR call failed with result XR_ERROR_CALL_ORDER_INVALID
[2023.12.14-13.05.09:480][968]LogOutputDevice: Warning: 

Script Stack (0 frames) :

[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff04c073b35 Dladdr: 0.025130ms Open: 0.011850ms Search: 0.013760ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff04c07258e Dladdr: 0.002020ms Open: 0.004559ms Search: 0.014550ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff0914ad322 Dladdr: 0.073219ms Open: 0.005620ms Search: 0.028680ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff0914aa50e Dladdr: 0.062399ms Open: 0.003270ms Search: 0.020450ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff09149e88c Dladdr: 0.051660ms Open: 0.003570ms Search: 0.025599ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff0914a06c8 Dladdr: 0.049390ms Open: 0.003419ms Search: 0.025470ms
[2023.12.14-13.05.09:480][968]LogCore: 0x00007ff0914a7f37 Dladdr: 0.040169ms Open: 0.003230ms Search: 0.023220ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff09149c68d Dladdr: 0.042719ms Open: 0.003300ms Search: 0.028010ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff09149be15 Dladdr: 0.040269ms Open: 0.003660ms Search: 0.024840ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff090c83286 Dladdr: 0.072639ms Open: 0.003320ms Search: 0.026039ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff091939631 Dladdr: 0.070039ms Open: 0.003470ms Search: 0.024840ms
[2023.12.14-13.05.09:481][968]LogCore: 0x0000000000242ce1 Dladdr: 0.001810ms Open: 0.006960ms Search: 0.015419ms
[2023.12.14-13.05.09:481][968]LogCore: 0x000000000024ecf9 Dladdr: 0.000890ms Open: 0.002950ms Search: 0.017860ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff09bbe5b31 Dladdr: 0.000480ms Open: 0.004020ms Search: 0.009170ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff08f2569c9 Dladdr: 0.010930ms Open: 0.002590ms Search: 0.000620ms
[2023.12.14-13.05.09:481][968]LogCore: 0x00007ff08f256a84 Dladdr: 0.008790ms Open: 0.002200ms Search: 0.000080ms
[2023.12.14-13.05.09:481][968]LogCore: 0x0000000000238508 Dladdr: 0.001370ms Open: 0.003380ms Search: 0.015660ms
[2023.12.14-13.05.09:481][968]LogStats: FPlatformStackWalk::StackWalkAndDump -  0.001 s
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: === Handled ensure: ===
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: 
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: Ensure condition failed: ((Result) >= 0)  [File:./../Plugins/Runtime/OpenXR/Source/OpenXRHMD/Private/OpenXRHMD.cpp] [Line: 1787] 
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: OpenXR call failed with result XR_ERROR_CALL_ORDER_INVALID
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: Stack: 
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff04c073b36 libUnrealEditor-OpenXRHMD.so!FOpenXRHMD::OnStereoStartup() [/mnt/horde/++UE5/Sync/Engine/Source/./../Plugins/Runtime/OpenXR/Source/OpenXRHMD/Private/OpenXRHMD.cpp:1787]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff04c07258f libUnrealEditor-OpenXRHMD.so!FOpenXRHMD::EnableStereo(bool) [/mnt/horde/++UE5/Sync/Engine/Source/./../Plugins/Runtime/OpenXR/Source/OpenXRHMD/Private/OpenXRHMD.cpp:841]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff0914ad323 libUnrealEditor-UnrealEd.so!UEditorEngine::GeneratePIEViewportWindow(FRequestPlaySessionParams const&, int, FWorldContext const&, EPlayNetMode, UGameViewportClient*, FSlatePlayInEditorInfo&) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:3451]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff0914aa50f libUnrealEditor-UnrealEd.so!UEditorEngine::CreateInnerProcessPIEGameInstance(FRequestPlaySessionParams&, FGameInstancePIEParameters const&, int) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:3082]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff09149e88d libUnrealEditor-UnrealEd.so!UEditorEngine::OnLoginPIEComplete_Deferred(int, bool, FString, FPieLoginStruct) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:1585]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff0914a06c9 libUnrealEditor-UnrealEd.so!UEditorEngine::CreateNewPlayInEditorInstance(FRequestPlaySessionParams&, bool, EPlayNetMode) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:1845]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff0914a7f38 libUnrealEditor-UnrealEd.so!UEditorEngine::StartPlayInEditorSession(FRequestPlaySessionParams&) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:2866]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff09149c68e libUnrealEditor-UnrealEd.so!UEditorEngine::StartQueuedPlaySessionRequestImpl() [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:1150]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff09149be16 libUnrealEditor-UnrealEd.so!UEditorEngine::StartQueuedPlaySessionRequest() [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/PlayLevel.cpp:1062]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff090c83287 libUnrealEditor-UnrealEd.so!UEditorEngine::Tick(float, bool) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/EditorEngine.cpp:1810]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff091939632 libUnrealEditor-UnrealEd.so!UUnrealEdEngine::Tick(float, bool) [/mnt/horde/++UE5/Sync/Engine/Source/./Editor/UnrealEd/Private/UnrealEdEngine.cpp:528]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x0000000000242ce2 UnrealEditor!FEngineLoop::Tick() [/mnt/horde/++UE5/Sync/Engine/Source/./Runtime/Launch/Private/LaunchEngineLoop.cpp:5819]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x000000000024ecfa UnrealEditor!GuardedMain(char16_t const*) [/mnt/horde/++UE5/Sync/Engine/Source/./Runtime/Launch/Private/Launch.cpp:190]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff09bbe5b32 libUnrealEditor-UnixCommonStartup.so!CommonUnixMain(int, char**, int (*)(char16_t const*), void (*)()) [/mnt/horde/++UE5/Sync/Engine/Source/./Runtime/Unix/UnixCommonStartup/Private/UnixCommonStartup.cpp:269]
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff08f2569ca libc.so.6!UnknownFunction(0x239c9)
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x00007ff08f256a85 libc.so.6!__libc_start_main(+0x84)
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: [Callstack] 0x0000000000238509 UnrealEditor!_start()
[2023.12.14-13.05.09:481][968]LogOutputDevice: Error: 
[2023.12.14-13.05.09:486][968]LogStats:                SubmitErrorReport -  0.000 s
[2023.12.14-13.05.09:497][968]LogStats:                    SendNewReport -  0.012 s
[2023.12.14-13.05.09:497][968]LogStats:             FDebug::EnsureFailed -  0.017 s
[2023.12.14-13.05.09:497][968]LogLoad: Game class is 'VRGameMode_C'
[2023.12.14-13.05.09:499][968]LogWorld: Bringing World /Game/VRTemplate/Maps/UEDPIE_0_VRTemplateMap.VRTemplateMap up for play (max tick rate 0) at 2023.12.14-08.05.09
[2023.12.14-13.05.09:499][968]LogWorld: Bringing up level for play took: 0.001376
[2023.12.14-13.05.09:499][968]LogOnline: OSS: Created online subsystem instance for: :Context_2
[2023.12.14-13.05.09:500][968]LogSlate: New Slate User Created. Platform User Id 8, User Index 8, Is Virtual User: 1
[2023.12.14-13.05.09:500][968]LogSlate: Slate User Registered.  User Index 8, Is Virtual User: 1
[2023.12.14-13.05.09:502][968]PIE: Server logged in
[2023.12.14-13.05.09:503][968]PIE: Play in editor total start time 0.501517 seconds.
[2023.12.14-13.05.09:515][968]LogViewport: Scene viewport resized to 422x1406, mode Windowed.
Resizing viewport due to setres change, 422 x 1406
[2023.12.14-13.05.09:528][969]LogViewport: Scene viewport resized to 349x1260, mode Windowed.
LogICUInternationalization: ICU TimeZone Detection - Raw Offset: -5:00, Platform Override: ''
LogInit: ExecutableName: CrashReportClient
LogInit: Build: ++UE5+Release-5.3-CL-29314046
LogInit: Engine Version: 5.3.2-29314046+++UE5+Release-5.3
LogInit: Compatible Engine Version: 5.3.0-27405482+++UE5+Release-5.3
LogInit: Net CL: 27405482
LogInit: OS: Gentoo Linux (6.6.2-gentoo-dist), CPU: AMD Ryzen 9 7950X 16-Core Processor, GPU: NVIDIA GeForce RTX 3080 Ti (NVIDIA UNIX x86_64 Kernel Module  545.29.06  Thu Nov 16 01:59:08 UTC 2023)
LogInit: Compiled (64-bit): Nov  3 2023 16:27:17
LogInit: Architecture: x64
LogInit: Compiled with Clang: 16.0.6 (github.com/llvm/llvm-project 7cbf1a2591520c2491aa35339f227775f4d3adf6)
LogInit: Build Configuration: Shipping
LogInit: Branch Name: ++UE5+Release-5.3
LogInit: Command Line:  -Abslog="/home/drew/.config/Epic/UnrealEngine/5.3/Saved/Logs/Mirage-CRC.log" -Unattended "/home/drew/.config/Epic/UnrealEngine/5.3/Saved/Crashes/ensureinfo-Mirage-pid-31633-8841973F9CA44493951EC3DA80BA57F8/"
LogInit: Base Directory: /home/drew/Games/Engine/Binaries/Linux/
LogInit: Allocator: Mimalloc
LogInit: Installed Engine Build: 1
LogInit: This binary is optimized with LTO: no, PGO: no, instrumented for PGO data collection: no
LogInit: Presizing for max 100000 objects, including 0 objects not considered by GC, pre-allocating 0 bytes for permanent pool.
LogInit: Object subsystem initialized

@mmrrqq
Copy link

mmrrqq commented Jan 16, 2024

I just ran into the same behavior using beta 2.3.1 and noticed that the SteamVR info panel still shows Now Playing <your_ue_project_name> when exiting the first VR preview window. The VR View is reset though.

The web console provides the following logs when exiting the VR preview from Unreal:

xrclient_UnrealEditorTue Jan 16 2024 11:01:46.048152 [Info] - Transitioning XrSession from XR_SESSION_STATE_VISIBLE to XR_SESSION_STATE_SYNCHRONIZED
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.048224 [Info] - Transitioning XrSession from XR_SESSION_STATE_SYNCHRONIZED to XR_SESSION_STATE_STOPPING
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.052675 [Info] - Transitioning XrSession from XR_SESSION_STATE_STOPPING to XR_SESSION_STATE_IDLE
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.052733 [Info] - Transitioning XrSession from XR_SESSION_STATE_IDLE to XR_SESSION_STATE_EXITING
vrserverTue Jan 16 2024 11:01:46.053251 [Info] - [OpenXR] No manifest. Clearing input data: system.generated.openxr.<my_UE_project_name>.unrealeditor.
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.072028 [Info] - Changing app type from VRApplication_OpenXRScene to VRApplication_OpenXRInstance
vrserverTue Jan 16 2024 11:01:46.072113 [Info] - AppInfoManager.ProcessQuit processid=15117 eLaunchingApp=LaunchingApp_None
vrserverTue Jan 16 2024 11:01:46.072151 [Info] - AppInfoManager.ProcessQuit: Clearing application system.generated.openxr.<my_UE_project_name>.unrealeditor PID was 15117
vrserverTue Jan 16 2024 11:01:46.072169 [Info] - AppInfoManager.ProcessQuit: Clearing application system.generated.openxr.<my_UE_project_name>.unrealeditor PID because 15117 has exited
vrserverTue Jan 16 2024 11:01:46.072267 [Info] - AppInfoManager.ProcessConnected BEGIN 15117 /home/mrothgaenger/dev/Linux_Unreal_Engine_5.3.2/Engine/Binaries/Linux/UnrealEditor 9 system.generated.openxr.<my_UE_project_name>.unrealeditor
vrserverTue Jan 16 2024 11:01:46.072307 [Info] - SetApplicationPid appkey=system.generated.openxr.<my_UE_project_name>.unrealeditor pid=15117, external transition
vrserverTue Jan 16 2024 11:01:46.072337 [Info] - SetApplicationPid: Setting app system.generated.openxr.<my_UE_project_name>.unrealeditor PID to 15117
vrserverTue Jan 16 2024 11:01:46.072376 [Info] - AppInfoManager.ProcessConnected END
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.072102 [Info] - Received message of type 1107 when 121 was expected on pipe VR_ServerPipe_12824
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.072129 [Warning] - IPC failure changing app type
xrclient_UnrealEditorTue Jan 16 2024 11:01:46.072153 [Error] - Unexpected error while trying to change the OpenXR application type: [VRInitError_Init_Internal]

and the following when trying to start the preview again:

xrclient_UnrealEditorTue Jan 16 2024 11:03:00.858994 [Info] - Initializing CVulkanVRRenderer
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.859068 [Info] - Debug markers: disabled, missing extension support. Is the Renderdoc layer enabled?
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.911567 [Info] - Initialized Vulkan transfer ring buffer, mapped at offset 0x0x7efd78000000.
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.912170 [Error] - Client connection in an invalid state [10], while attempting to transition application to VrApplication_OpenXRScene.
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.928290 [Info] - Changing app type from VRApplication_OpenXRScene to VRApplication_OpenXRInstance
vrserverTue Jan 16 2024 11:03:00.928462 [Info] - Refusing to change app type from 15117: UnrealEditor transition from VRApplication_OpenXRInstance to VRApplication_OpenXRInstance is illegal
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.928550 [Info] - Discarding sequence mismatched message type: 121, sequence: 446, expected type: 121, expected sequence: 447, pipe: VR_ServerPipe_12824
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.928597 [Warning] - ChangeAppType failed with VRInitError_Init_IllegalTypeTransition
xrclient_UnrealEditorTue Jan 16 2024 11:03:00.928665 [Error] - Unexpected error while trying to change the OpenXR application type: [VRInitError_Init_IllegalTypeTransition]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants