03-14-2024 01:20 PM
Engine: Unity 2022.3.18f1
Meta Avatar SDK: 24.1.1
Other Meta XR SDKs: 60.0.0
Hardware where we've encountered this issue:
While loading avatars, we intermittently receive this error:
ERROR: [ovrAvatar2 entity] Could not map primitive 0 to the entity pose. Joint 0 RootNode not foundOculus.Avatar2.OvrAvatarEntity:BuildPrimitiveRenderable(UInt32)
Oculus.Avatar2.<BuildNewPrimitiveRenderablesASync>d__265:MoveNext()
Oculus.Avatar2.<LoadASync_BuildPrimitives_Internal>d__273:MoveNext()
Oculus.Avatar2.OvrAvatarEntity:LoadSync_BuildPrimitives_Internal(CheckPrimitivesResult&)
Oculus.Avatar2.<LoadAsyncCoroutine_BuildPrimitives_Internal>d__269:MoveNext()
Oculus.Avatar2.<LoadAsync_BuildPrimitives>d__256:MoveNext()
Oculus.Avatar2.<LoadAsync_BuildSkeletonAndPrimitives>d__255:MoveNext()
Oculus.Avatar2.OvrTime:CutSlice(Int32&, Int32&)
Oculus.Avatar2.OvrTime:RunSlices()
Oculus.Avatar2.OvrTime:RunWork()
Oculus.Avatar2.OvrTime:InternalUpdate()
Oculus.Avatar2.OvrAvatarManager:UpdateInternal(Single)
It is then followed by a null reference exception
NullReferenceException: Object reference not set to an instance of an object.Oculus.Avatar2.OvrAvatarEntity.OnRenderableCreated (Oculus.Avatar2.OvrAvatarRenderable newRenderable) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<BuildNewPrimitiveRenderablesASync>d__265.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadASync_BuildPrimitives_Internal>d__273.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity.LoadSync_BuildPrimitives_Internal (Oculus.Avatar2.OvrAvatarEntity+CheckPrimitivesResult& result) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsyncCoroutine_BuildPrimitives_Internal>d__269.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsync_BuildPrimitives>d__256.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsync_BuildSkeletonAndPrimitives>d__255.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.CutSlice (System.Int32& index, System.Int32& stopIndex) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.RunSlices () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.RunWork () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.InternalUpdate () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarManager.UpdateInternal (System.Single deltaSeconds) (at <00000000000000000000000000000000>:0)
I have not been able to find any other mentions of this error. Any advice is appreciated.
Here is a more complete trace of the ovrAvatar2 logging from an execution where we encountered this error on a Quest 2. User IDs and urls have been removed.
[00:00:411] [ovrAvatar2 manager] Identified Quest platform!
[00:00:412] [ovrAvatar2 manager] OvrAvatarManager initializing for app <our-app-name>::v0.0.3+Unity_2022.3.18f1 on platform 'Quest2'
[00:00:412] [ovrAvatar2 manager] Attempting to initialize ovrplugintracking lib
[00:00:414] [ovrAvatar2 native] DynLib::OVRPlugin library 'libOVRPlugin.so' found
[00:00:414] [ovrAvatar2 native] Tracking::Found ovrplugin version 1.92.0.
[00:00:415] [ovrAvatar2 native] Tracking::ovrpTracking_CreateFaceTrackingContext succeeded.
[00:00:415] [ovrAvatar2 native] Tracking::ovrpTracking_CreateFaceTrackingContext succeeded.
[00:00:416] [ovrAvatar2 manager] Created ovrplugintracking face tracking context
[00:00:417] [ovrAvatar2 native] Tracking::ovrpTracking_CreateEyeTrackingContext succeeded.
[00:00:418] [ovrAvatar2 native] Tracking::ovrpTracking_CreateEyeTrackingContext succeeded.
[00:00:418] [ovrAvatar2 manager] Created ovrplugintracking eye tracking context
[00:00:419] [ovrAvatar2 native] Tracking::ovrpTracking_CreateHandTrackingContext succeeded.
[00:00:419] [ovrAvatar2 native] Tracking::ovrpTracking_CreateHandTrackingContext succeeded.
[00:00:419] [ovrAvatar2 manager] Created ovrplugintracking hand tracking delegate
[00:00:421] [ovrAvatar2 T][Debug] Marking DontDestroyOnLoad on singleton
[00:00:422] [ovrAvatar2][Debug] Initializing GPUSkinning Singletons
[00:00:438] [ovrAvatar2 native] System::Version info: "Avatar2 runtime SDK 24.1.0.382.244 client SDK 24.1.0.382.244", Platform: quest2
[00:00:439] [ovrAvatar2 native] System::VR subsystem: Unknown / none detected
[00:00:441] [ovrAvatar2 T][Debug] Marking DontDestroyOnLoad on singleton
[00:00:442] [ovrAvatar2 native] Loader::Added SampleAssets/PresetAvatars_Quest.zip as zip source
[00:00:442] [ovrAvatar2 manager][Debug] Added zip source SampleAssets/PresetAvatars_Quest.zip
[00:00:443] [ovrAvatar2 native] Loader::Added SampleAssets/PresetAvatars_Ultralight.zip as zip source
[00:00:443] [ovrAvatar2 manager][Debug] Added zip source SampleAssets/PresetAvatars_Ultralight.zip
[00:00:444] [ovrAvatar2 native] Loader::Added SampleAssets/PresetAvatars_Quest_Light.zip as zip source
[00:00:444] [ovrAvatar2 manager][Debug] Added zip source SampleAssets/PresetAvatars_Quest_Light.zip
[00:00:446] [ovrAvatar2 manager] OvrAvatarManager initialized app with target version: -1.-1.-1.-1
[00:00:447] [ovrAvatar2 T][Debug] Marking DontDestroyOnLoad on singleton
[00:00:460] OVRPlugin.supportedFrequencies: [60, 72, 80, 90, 120]
[00:00:461] OVRManager.loadedXRDevice is Oculus
[00:06:037] [OVRManager] HMDAcquired event
[00:06:038] [OVRManager] HMDMounted event
[00:06:039] [OVRManager] VrFocusAcquired event
[00:06:041] [OVRManager] TrackingAcquired event
[00:06:325] [OVRManager] OnApplicationPause(true)
[00:06:829] [OVRManager] OnApplicationFocus(false)
[00:06:896] [OVRManager] OnApplicationFocus(true)
[00:06:914] [OVRManager] OnApplicationPause(false)
[00:06:919] [ovrAvatar2 native] Loader::Asset loaded from disk: ".../chr00000CharS00.rig.zip"
[00:06:921] [ovrAvatar2 native] Loader::Asset loaded from disk: ".../default.behavior.zip"
[00:06:921] [ovrAvatar2 native] Loader::Asset loaded from disk: ".../mood.animstatemachine"
[00:06:922] [ovrAvatar2 native] Loader::Asset loaded from disk: ".../blank.glb.zst"
[00:07:043] [ovrAvatar2 native] Animation::Successfully loaded rtrig assets from: zip://chr00000CharS00.rig.zip
[00:07:043] [ovrAvatar2 native] Animation::Successfully loaded hierarchy from: zip://chr00000CharS00.rig.zip
[00:07:044] [ovrAvatar2 native] Animation::Successfully loaded rig asset from: zip://chr00000CharS00.rig.zip
[00:07:045] [ovrAvatar2 OvrPlatformInit][Debug] Successfully retrieved access token.
[00:07:112] [ovrAvatar2 native] Animation::Successfully loaded behavior from: zip://default.behavior.zip
[00:07:170] [ovrAvatar2 resourceLoader][Debug] Mapped resource id:880
[00:07:184] [ovrAvatar2] staring primitive load for loader: 880
[00:07:187] [ovrAvatar2] staring primitive load for loader: 880
[00:07:199] [ovrAvatar2] staring primitive load for loader: 880
[00:07:200] [ovrAvatar2] staring primitive load for loader: 880
[00:07:232] [ovrAvatar2 ovrAvatarPrimitive][Debug] Created image for id 881
[00:07:233] [ovrAvatar2 ovrAvatarPrimitive][Debug] Created image for id 882
[00:07:233] [ovrAvatar2 ovrAvatarPrimitive][Debug] Created image for id 883
[00:07:569] [ovrAvatar2 entity][Debug] Base ConfigureCreationInfo Invoked
[00:07:570] [ovrAvatar2 entity] SkinningType of Avatar 'LocalOvrAvatar(Clone)' set to OVR_COMPUTE
[00:07:571] [ovrAvatar2 native] Entity::RtRig is enabled on Entity 2
[00:07:572] [ovrAvatar2 native] Entity::Behavior system is enabled on Entity 2
[00:07:573] [ovrAvatar2 entity] [2] OnCreated
[00:07:576] [ovrAvatar2 entity][Debug] Entity 2 created as a local avatar
[00:07:578] [ovrAvatar2 entity][Debug] Base ConfigureEntity Invoked
[00:07:590] [ovrAvatar2 entity][Debug] Base ConfigureCreationInfo Invoked
[00:07:591] [ovrAvatar2 entity] SkinningType of Avatar 'RemoteOvrAvatarVariant(Clone)' set to OVR_COMPUTE
[00:07:591] [ovrAvatar2 native] Entity::RtRig is enabled on Entity 3
[00:07:591] [ovrAvatar2 native] Entity::ovrAvatar2EntityFeatures_BehaviorSystem cannot be enabled when ovrAvatar2EntityFeature_Animation is not enabled
[00:07:592] [ovrAvatar2 entity] [3] OnCreated
[00:07:593] [ovrAvatar2 entity][Debug] Entity 3 created as a remote avatar
[00:07:594] [ovrAvatar2 entity][Debug] Base ConfigureEntity Invoked
[00:07:780] [ovrAvatar2 native] RigGraphCompiler::Assembling joint chains
[00:07:780] [ovrAvatar2 native] RigGraphCompiler::Assembling face chains
[00:07:789] [ovrAvatar2 native] RigGraphCompiler::Assembling joint chains
[00:07:789] [ovrAvatar2 native] RigGraphCompiler::Added an implicit orient contraint from RTRig_Pelvis to RTRig_R_Hip
[00:07:789] [ovrAvatar2 native] RigGraphCompiler::Added an implicit parent contraint from RTRig_R_Hip to RTRig_R_Ankle
[00:07:790] [ovrAvatar2 native] RigGraphCompiler::Added an implicit orient contraint from RTRig_Pelvis to RTRig_L_Hip
[00:07:790] [ovrAvatar2 native] RigGraphCompiler::Added an implicit parent contraint from RTRig_L_Hip to RTRig_L_Ankle
[00:07:790] [ovrAvatar2 native] RigGraphCompiler::Assembling face chains
[00:07:791] [ovrAvatar2 native] RetargetLayer::Retarget layer initialized on entity 2
[00:07:791] [ovrAvatar2 native] SkeletalConstraintSolverLayer::Skeletal constraint solver layer initialized
[00:07:840] [ovrAvatar2 ResourceTimers][Debug] Resource 880 asset loading time: 0.6720619
[00:07:889] [ovrAvatar2 ResourceTimers][Debug] Resource 880 total creation time: 0.7210188
[00:07:892] [ovrAvatar2 entity] No skeleton loaded
[00:07:897] [ovrAvatar2 native] LoadRequest::[1] entity[3] started in state=PendingSpecification
[00:07:897] [ovrAvatar2 native] Asset::[1] Starting loadUser for entity 3
[00:07:898] [ovrAvatar2 entity][Debug] Loaded user ID <userID1> onto entity 3
[00:07:928] ERROR: [ovrAvatar2 entity] Could not map primitive 0 to the entity pose. Joint 0 RootNode not foundOculus.Avatar2.OvrAvatarEntity:BuildPrimitiveRenderable(UInt32)
Oculus.Avatar2.<BuildNewPrimitiveRenderablesASync>d__265:MoveNext()
Oculus.Avatar2.<LoadASync_BuildPrimitives_Internal>d__273:MoveNext()
Oculus.Avatar2.OvrAvatarEntity:LoadSync_BuildPrimitives_Internal(CheckPrimitivesResult&)
Oculus.Avatar2.<LoadAsyncCoroutine_BuildPrimitives_Internal>d__269:MoveNext()
Oculus.Avatar2.<LoadAsync_BuildPrimitives>d__256:MoveNext()
Oculus.Avatar2.<LoadAsync_BuildSkeletonAndPrimitives>d__255:MoveNext()
Oculus.Avatar2.OvrTime:CutSlice(Int32&, Int32&)
Oculus.Avatar2.OvrTime:RunSlices()
Oculus.Avatar2.OvrTime:RunWork()
Oculus.Avatar2.OvrTime:InternalUpdate()
Oculus.Avatar2.OvrAvatarManager:UpdateInternal(Single)
[00:07:930] EXCEPTION: NullReferenceException: Object reference not set to an instance of an object.Oculus.Avatar2.OvrAvatarEntity.OnRenderableCreated (Oculus.Avatar2.OvrAvatarRenderable newRenderable) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<BuildNewPrimitiveRenderablesASync>d__265.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadASync_BuildPrimitives_Internal>d__273.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity.LoadSync_BuildPrimitives_Internal (Oculus.Avatar2.OvrAvatarEntity+CheckPrimitivesResult& result) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsyncCoroutine_BuildPrimitives_Internal>d__269.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsync_BuildPrimitives>d__256.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarEntity+<LoadAsync_BuildSkeletonAndPrimitives>d__255.MoveNext () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.CutSlice (System.Int32& index, System.Int32& stopIndex) (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.RunSlices () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.RunWork () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrTime.InternalUpdate () (at <00000000000000000000000000000000>:0)
Oculus.Avatar2.OvrAvatarManager.UpdateInternal (System.Single deltaSeconds) (at <00000000000000000000000000000000>:0)
[00:08:123] [ovrAvatar2 native] LoadRequest::[2] entity[3] started in state=PendingSpecification
[00:08:123] [ovrAvatar2 native] Asset::[2] Starting loadUser for entity 3
[00:08:123] [ovrAvatar2 native] LoadRequest::[2] entity[3] state=Failed, reason: CdnLoadInProgress, response 0
[00:08:124] [ovrAvatar2 entity][Debug] Loaded user ID <userID1> onto entity 3
[00:08:124] [ovrAvatar2 entity] [3] OnLoadFailed requestId=2 (CdnLoadInProgress)
[00:08:405] [ovrAvatar2 native] LoadRequest::[3] entity[2] started in state=PendingSpecification