"Random" crashes

[Trabber]

I have gotten 3 crashes in 2 days. After poking around in the logs, and the unity docs, and the code here, I am fairly confident that the core cause of all of them is that UnityEngine.Object.FindObjectsOfType() is not thread safe.

From a game play perspective, there did not feel like any pattern to them, although it looks like technically the last thing I did each time was enter a new area (map pixel or scene). I suspect that I have seen so many and I can't find reports from other people because more mods would make these race conditions more common and I am running something like 80 mods, so most people who get the crash would also attribute this to one or more of these mods. (I reported it to Travel Options first)

Specifically, the crashes are Access Violations in UnityEngine.Object.FindObjectsOfType(). In 2 crashes this was called by DaggerfallWorkshop.PlayerGPS.UpdateNearbyObjects() and it was called by DaggerfallWorkshop.Game.GameManager.AreEnemiesNearby() in the third.

In my experience (10 years as a software engineer, most of that C#) an access violation in a C# app is almost always one of: pinvoke, unsafe code, or a thread safety issue. In particular using any of the .Net collection types which are not explicitly thread safe in a multi-threaded environment can cause Access Violations and that is by for the most common cause I have seen. Looking for other instances of this crash I have found quite a few other unity projects with reports of random crashes on only some user's systems that come from this method, which also sounds like race condition hell to me.

My recommended fixes come in 2 flavors:
A. Try to get Unity to make that method thread safe (if I understand what it is actually doing, that would be really hard).
B. Eliminate uses of this method in any potentially concurrent code, which looks like all 19 uses of this function in daggerfall-unity to me. And that requires some type of thread safe tracking for the 9 types which this is used to find. I have not looked at the modding API so I do not know how hard it would be to force a factory pattern on those 9 types and it has been so long since I used mono that I have no idea if you have access to weak references which is definitely the easy way to do that type of instance tracking.

I am between jobs right now so I will try to spend some time poking at option B, based on the docs it should come with some performance benefits in addition to being a potential crash fix, also I have never actually used unity before so it might be fun to see how this works. How/where would you like such further investigation communicated?

[Trabber]

Daggerfall Crashes 2022-06-17_18.zip

Oops, failed to actually upload the crash data.

[Interkarma]

I'm mainly seeing a lot "index out of range" exceptions in your error logs, which are mod-related (Loot Menu Mod).

ArgumentOutOfRangeException: Index was out of range. Must be non-negative and less than the size of the collection.
Parameter name: index
  at System.ThrowHelper.ThrowArgumentOutOfRangeException (System.ExceptionArgument argument, System.ExceptionResource resource) [0x00029] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.ThrowHelper.ThrowArgumentOutOfRangeException () [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at LootMenuMod.LootMenu.OnGUI () [0x00542] in <9602d6533cfa4cbd956615c29094eaf3>:0 

Please remove all mods before opening an issue to confirm your stability problems are actually with base Daggerfall Unity or have been introduced by mods. If the crashing only happens with mods installed, please try to isolate which one and raise with creator of that mod.

I'm not aware of any crashing issues like this in base DFU. FindObjectsOfType() can only be called from the main thread, which should always the case in DFU.

I am happy to investigate further if you can reproduce with no mods installed. For good measure, please setup fresh using the recommended DaggerfallGameFiles method. If you're using repacks made by others (such as the GOG Cut), I specifically do not provide support for these distributions.

[Interkarma]

Edit: I am interested in discussion about this one, and feel that I closed out of hand. From what you're saying a large number of mods is basically a prerequisite to trigger the problem. I'll open back up for now.

I'll also tag @KABoissonneault. I'd love to know his thoughts on the thread safety question, if possible.

And since you mention Travel Options, maybe @ajrb can chime in.

[KABoissonneault]

I'm not sure. At first, I thought it was possible AreEnemiesNearby checks could be called from the UI thread while the Game thread was spawning enemies, but it seems all DFU code for UI eventually goes back to MonoBehaviour.Update, which is called from the Game thread.

For sure, solution B could be beneficial regardless of concurrency issues. As suggested in the page for FindObjectsOfType (https://docs.unity3d.com/ScriptReference/Object.FindObjectsOfType.html), we could have a singleton track all the objects created by GameObjectHelper.CreateEnemy, which is also used by mods like World of Daggerfall, and replace FindObjectsOfType calls with querying that "enemy manager".
First, this would be a performance improvement for all code involving checks for enemies.
Second, we could lock access to this enemy list behind a ReaderWriterLock (exclusive write lock for GameObjectHelper.CreateEnemy, shared read lock for everything else), which would ensure we don't have unsafe cases of UI code reading the enemy list while the Game thread adds or removes from it.

Overall, I'm not sure DFU is directly at fault for the crash, as everything is in game thread. World of Daggerfall is probably the source of dynamically spawned enemies (they can spawn any time a terrain loads). While the terrain system uses the UnityJobs system, all the events are called on the Game thread from what I can see, so again WoD would only spawn enemies on the game thread.

But since I don't think the change would hurt DFU, while potentially increasing mod stability, I think we can do it.

Want me to tackle this one?

[Trabber]

An Access Violation would typically be generated by reading a collection while members are being removed. So I would expect this to happen if FindObjectsOfType is being used concurrently with Destroy or DestroyImmediate. Actually, on closer reading Destroy is probably safe. I am trying to figure out Unity and the DFU code base at the same time, so sorry that I am mostly giving generalizations.

[Interkarma]

I'm not sure. At first, I thought it was possible AreEnemiesNearby checks could be called from the UI thread while the Game thread was spawning enemies, but it seems all DFU code for UI eventually goes back to MonoBehaviour.Update, which is called from the Game thread.

That's an interesting idea. The underlying DaggerfallUI class uses Monobehaviour.Update() to call TopWindow.Update(), so yeah that should be on game thread. Then it uses OnGUI() to call TopWindow.Draw() for rendering tasks. I don't think any methods are doing scene searches during Draw() (they shouldn't be).

AreEnemiesNearby() can also be triggered through PlayerEntity_OnExhausted. I'd assume that would execute on game thread also, but it could trigger at unexpected times while code is doing other setup. Would require the player to run out of stamina at just the wrong moment though. Maybe a possibility?

AFAIK other uses should only trigger during game thread.

Want me to tackle this one?

I'm always happy to have your help Kab. :) If this is something you feel would help with performance in WoD and other mods, then we should discuss. There are a few concerns on my end (e.g. tracking destroyed and disabled enemies as well) but I trust we'll be able to sort that out. For now, I'm mainly wanting to dive into Trabber's hypothesis.

Regarding performance, I built the NearbyObjects system to help centralise and offload scene searches for several object types. It's not quite realtime (updates 3 times a second) but I think that would be adequate to replace most uses of AreEnemiesNearby() in other parts of code. This might be a good place to start that doesn't require much refactoring to test if searching enemies is even causing a race condition like Trabber suggests. We first lower the number of scene searches so that only NearbyObjects is doing the work. This runs in PlayerGPS.Update() and should always be on game thread.

[Trabber]

I think there is one point of my hypothesis I did not communicate well. I am not worried about 2 instances of FindObjectsOfType running concurrently, I am worried that FindObjectsOfType is running concurrently with code which modifies the underlying collection being searched.

Methods which my hypothesis say should not be allowed to run concurrently with FindObjectsOfType include any method which:

• schedules a component or GameObject to be garbage collected, or
• registers a GameObject with the engine, or
• adds a component to a registered GameObject, or
• (unsure) sets GameObjects activate or inactivate

The highest risk comes from the first type of activity which is why I mentioned DestroyImmediate in my prior comment. But the whole set combined covers enough possibilities that I just assumed with my initial report it would be basically impossible to ensure it all ran on one thread.

With that said, I still don't know how to tell what runs on which thread. But, my gut tells me OnWillRenderObject should be running on the GUI thread and that causes me to worry about the Water MonoBahavior calling DestroyImmediate in that event handler, but that may be dead code since I cannot find Water getting added to any GameObjects.

Edit: I also have not figured out how the engine becomes aware of a GameObject, I am starting to assume it just happen automatically in the constructor or something.

[Interkarma]

AFAIK there's no use of DestroyImmediate in play. It's only used in context of editor (which is fine). Unity generates a warning in the output logs we'd see if DestroyImmediate was called during play context. The Water component you mention is part of Unity's own Standard Assets package and is not attached to anything in DFU.

I do understand what you're saying though. My approach above is to limit how often FindObjects scene searches are called to the one pathway. This is easy to do within the current framework and doesn't require much refactoring. I'm trying to start from a point of "least impact" since the actual cause of your crashes is technically unknown, and doesn't occur in unmodded DFU that I'm aware of. I'm resistant to making large changes just yet.

[Trabber]

Sounds good and practical. Thanks for looking at it.

[KABoissonneault]

Just FYI, I was doing an unrelated playtest with a player just now, and they've reproduced this crash. Pretty clear from the callstack

========== OUTPUTTING STACK TRACE ==================

0x00007FFEEBB937D0 (UnityPlayer) UnityMain
0x00007FFEEBEC0119 (UnityPlayer) UnityMain
0x00007FFEEBF54D74 (UnityPlayer) UnityMain
0x000002D5984E80EA (Mono JIT Code) (wrapper managed-to-native) UnityEngine.Object:FindObjectsOfType (System.Type)
0x000002D5C458A773 (Mono JIT Code) UnityEngine.Object:FindObjectsOfType<T_REF> ()
0x000002D5EB9B7DBB (Mono JIT Code) DaggerfallWorkshop.Game.EnemySenses:GetTargets ()
0x000002D5EB9B0AB3 (Mono JIT Code) DaggerfallWorkshop.Game.EnemySenses:FixedUpdate ()
0x000002D54D61A800 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007FFEEAFAE270 (mono-2.0-bdwgc) mono_get_runtime_build_info
0x00007FFEEAF32AE2 (mono-2.0-bdwgc) mono_perfcounters_init
0x00007FFEEAF3BB3F (mono-2.0-bdwgc) mono_runtime_invoke
0x00007FFEEBEC3D3D (UnityPlayer) UnityMain
0x00007FFEEBEC10C3 (UnityPlayer) UnityMain
0x00007FFEEBEAA293 (UnityPlayer) UnityMain
0x00007FFEEBEAA34D (UnityPlayer) UnityMain
0x00007FFEEBC36EC0 (UnityPlayer) UnityMain
0x00007FFEEBD84997 (UnityPlayer) UnityMain
0x00007FFEEBD84A33 (UnityPlayer) UnityMain
0x00007FFEEBD86E8C (UnityPlayer) UnityMain

Here's the full logs
Player(5).log
.
Seems clear that the crash really is going on in the wild.

[Interkarma]

Thanks Kab. To give me a bit more info, what was player doing in game at time of crash? Were they in a dungeon, travelling across overworld, etc?

[KABoissonneault]

They say they were in a dungeon. Kind of surprising to be honest, I didn't think there would much things in parallel in there.

[Interkarma]

Cheers, that's good to know.

Thinking about this one further, the way EnemySenses works here is pretty aggressive even without parallel threads. There's a throttle in place so this isn't running 60 times a second per enemy or anything, but it's still a lot of extra load and potential for trouble.

I'm going to make this one a priority for 0.14.1 and release an update in another week to start remediating the excessive use of FindObjectsOfType in core.

Thank you both for all your input.

[Interkarma]

I didn't end up giving this one the priority promised, I'm sorry. I'm actually somewhat curious if the recent engine patch also helps remediate the access violation inside engine. I'm not sure that's easy to test however, and probably better just for me to move forwards with the changes I have in mind to reduce how frequently FindObjectsOfType is used in core.

I'll loop back to this one when I can.

[KABoissonneault]

Just bumping this to mention that the crash is still happening out there. Probably one of the more important things we should fix in the next update

Player(6).log

[John-Leitch]

My time is somewhat constrained, but I find this to be an interesting issue. As expected based on the lack of detailed symbols in the logged stack, FindObjectOfType ultimately calls into native code. It does this indirectly, through FindObjectsOfType:

	[MethodImpl(MethodImplOptions.InternalCall)]
	[TypeInferenceRule(TypeInferenceRules.ArrayOfTypeReferencedByFirstArgument)]
	[FreeFunction("UnityEngineObjectBindings::FindObjectsOfType")]
	public static extern UnityEngine.Object[] FindObjectsOfType(Type type);

Given this, I decided to look at what kind of artifacts were in the zip @Trabber provided (still entirely new to this project, so I didn't know what to expect). It was nice to see a memory dump, and even nicer of Unity to provide symbols: https://docs.unity3d.com/Manual/WindowsDebugging.html

Loading up one of the crashdumps in WinDbg and running !analyze after adding the symbol server provided by unity gives a much nicer stack for the native side of things:

000000aa`bb6ee9b0 00007ffc`1c3f0119     : 00000000`00000001 00000278`4f93cde0 00000000`00004b80 00000276`8740fed0 : UnityPlayer!GameObject::IsActive+0x50
000000aa`bb6ee9e0 00007ffc`1c484d74     : 000000aa`bb6eebc8 000000aa`bb6ef280 00000000`00000001 00000277`5cbee1c8 : UnityPlayer!Scripting::FindObjectsOfType+0x409
000000aa`bb6eeb90 00000277`a6ed80ea     : 00000277`5d25f840 00000277`5d25f840 000000aa`bb6eec30 00000277`5ea47833 : UnityPlayer!Object_CUSTOM_FindObjectsOfType+0x44
000000aa`bb6eebc0 00000278`49236a73     : 000000aa`bb6ef280 00000275`f3a0c440 00000277`5e2953a8 00007ffc`1eeaf530 : 0x00000277`a6ed80ea
000000aa`bb6eec40 00000278`49236403     : 000000aa`00000000 000000aa`bb6ef280 00000000`00000000 00000277`a6b08c60 : 0x00000278`49236a73
000000aa`bb6eec80 00000277`d2c30d8b     : 000000aa`00000000 000000aa`bb6ef280 00000277`d2c2c120 00000277`c7c560f0 : 0x00000278`49236403
000000aa`bb6eee10 00000277`5ea2a800     : 00000000`00000000 00007ffc`1ee0bec9 000000aa`bb6ef010 00007ffc`1bbc5529 : 0x00000277`d2c30d8b
000000aa`bb6eee60 00007ffc`1ef1e270     : 000000aa`a5076ff0 000000aa`bb6ef150 000000aa`00000000 00000277`5d75dee0 : 0x00000277`5ea2a800
000000aa`bb6eeef0 00007ffc`1eea2ae2     : 00000275`f3963574 00000277`5d791c88 000000aa`bb6ef2e0 000000aa`bb6ef180 : mono_2_0_bdwgc!mono_jit_runtime_invoke+0x530
000000aa`bb6ef0d0 00007ffc`1eeabb3f     : 000000aa`bb6ef280 00000277`c7b74960 000000aa`bb6ef2f0 00000000`00000000 : mono_2_0_bdwgc!do_runtime_invoke+0x82
000000aa`bb6ef120 00007ffc`1c3f3d3d     : 00000277`c7b74960 00000000`00000000 00007ffc`1eeabad0 00000000`3f800000 : mono_2_0_bdwgc!mono_runtime_invoke+0x6f
000000aa`bb6ef1d0 00007ffc`1c3f10c3     : 00000000`00000000 000000aa`bb6ef3d0 000000aa`bb6ef280 000000aa`bb6ef290 : UnityPlayer!scripting_method_invoke+0x3d
000000aa`bb6ef200 00007ffc`1c3da293     : 00000277`c7b74960 00000277`70fe4d60 00000000`00000000 00000277`5d75dee0 : UnityPlayer!ScriptingInvocation::Invoke+0x93
000000aa`bb6ef260 00007ffc`1c3da34d     : 00000277`c7b74960 00000276`4006e4d0 000000e4`4a7e6839 00000000`00000000 : UnityPlayer!MonoBehaviour::CallMethodIfAvailable+0xc3
000000aa`bb6ef3d0 00007ffc`1c166cc0     : 00000277`c7b74960 00000276`4006e4d0 00000277`c7b74960 00000276`403f1250 : UnityPlayer!MonoBehaviour::CallUpdateMethod+0x9d
000000aa`bb6ef400 00007ffc`1c2b4997     : 00000276`80b5f8c8 00000276`80b5f930 00000000`00000000 00000276`00000000 : UnityPlayer!BaseBehaviourManager::CommonUpdate<BehaviourManager>+0x170
000000aa`bb6ef470 00007ffc`1c2b4a33     : 00000000`00000000 00000000`00000000 00000276`80b5f8c8 00000000`80000012 : UnityPlayer!ExecutePlayerLoop+0x57
000000aa`bb6ef610 00007ffc`1c2b6e8c     : 00000000`00000910 00000275`f3963574 00000000`00000910 00000000`00000001 : UnityPlayer!ExecutePlayerLoop+0xf3
000000aa`bb6ef7b0 00007ffc`1c06628e     : 00000000`00000001 00000000`00000000 00000000`00000001 00000275`f3963574 : UnityPlayer!PlayerLoop+0x10c
000000aa`bb6ef830 00007ffc`1c064fea     : 00000000`00000910 00000000`00000000 00000000`00000000 00000000`00000000 : UnityPlayer!PerformMainLoop+0x1be
000000aa`bb6ef860 00007ffc`1c06909c     : 00000000`00000001 00000000`00000000 00000000`00000000 00000000`00000000 : UnityPlayer!MainMessageLoop+0xda
000000aa`bb6ef8d0 00007ffc`1c06cb8b     : 00000000`00000001 00000000`00000000 00000000`00000000 00000000`00000000 : UnityPlayer!UnityMainImpl+0xecc
000000aa`bb6ffb80 00007ff7`367c11f2     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : UnityPlayer!UnityMain+0xb
000000aa`bb6ffbb0 00000000`00000000     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : DaggerfallUnity!__scrt_common_main_seh+0x106

From the hip, it looks like the pointer to GameObject itself got corrupted:

0:000> .frame d
0d 000000aa`bb6ee9b0 00007ffc`1c3f0119     UnityPlayer!GameObject::IsActive+0x50 [c:\buildslave\unity\build\runtime\baseclasses\gameobject.cpp @ 420] 
0:000> dv
                          this = 0x00000276`401b1590
                           trs = <value unavailable>
                        parent = <value unavailable>
TypeContainer<Transform>::rtti = struct RTTI
TypeContainer<Transform>::rtti = struct RTTI
0:000> ?? this
class GameObject * 0x00000276`401b1590
   +0x000 __VFN_table : ???? 
   =00007ffc`1d2fea80 ms_IDToPointer   : ???? 
   =00007ffc`1d2fea88 ms_TypeToObjectSet : ???? 
   +0x008 m_InstanceID     : ??
   +0x00c m_MemLabelIdentifier : ??
   +0x00c m_TemporaryFlags : ??
   +0x00c m_HideFlags      : ??
   +0x00c m_IsPersistent   : ??
   +0x00c m_CachedTypeIndex : ??
   +0x010 m_EventIndex     : ???? 
   +0x018 m_MonoReference  : ScriptingGCHandle
   +0x030 m_Component      : dynamic_array<GameObject::ComponentPair,0>
   +0x050 m_Layer          : ??
   +0x054 m_Tag            : ??
   +0x056 m_IsActive       : ??
   +0x057 m_IsActiveCached : ??
   +0x058 m_ActivationState : ??
   +0x05c m_SupportedMessages : ??
   +0x060 m_Name           : ConstantString
   +0x068 m_ActiveGONode   : ListNode<GameObject>
   =00007ffc`1d2feb08 s_GameObjectDestroyedCallback : ???? 
   =00007ffc`1d2feb10 s_SetGONameCallback : ???? 
0:000> dd this
00000276`401b1590  ???????? ???????? ???????? ????????
00000276`401b15a0  ???????? ???????? ???????? ????????
00000276`401b15b0  ???????? ???????? ???????? ????????
00000276`401b15c0  ???????? ???????? ???????? ????????
00000276`401b15d0  ???????? ???????? ???????? ????????
00000276`401b15e0  ???????? ???????? ???????? ????????
00000276`401b15f0  ???????? ???????? ???????? ????????
00000276`401b1600  ???????? ???????? ???????? ????????

The next (non-inlined) frame up, things look like they are okay.

0:000> .frame 10
10 000000aa`bb6ee9e0 00007ffc`1c484d74     UnityPlayer!Scripting::FindObjectsOfType+0x409 [c:\buildslave\unity\build\runtime\scripting\scripting.cpp @ 945] 
0:000> dv
       systemTypeInstance = class ScriptingSystemTypeObjectPtr
                     mode = kFindActiveSceneObjects (0n1)
                    count = 0n1
             compareKlass = class ScriptingClassPtr
                  objects = struct dynamic_array<Object *,0>
         scriptingObjects = 0x00000276`60008040
                   result = class ScriptingArrayPtr
                     type = <value unavailable>
autoFree_scriptingObjects = class AutoFree
                klassName = <value unavailable>
                    size_ = <value unavailable>
                     ptr_ = <value unavailable>
              allocaSize_ = <value unavailable>
                        i = 0x72e
                   object = 0x00000276`875068c0
                     mono = class ScriptingObjectPtr
                    klass = class ScriptingClassPtr

Unfortunately, it's quite time consuming to dive further into this matter without source access. I've looked a bit with Ghidra, but did so before I realized symbols and crashdumps were available. Maybe I can put some further time into this with the goal of verifying lack of thread safety.

Edit:

I looked at the native stacks for all three crashes, and they're the same. However, one other thing: the stack above is !analyze output, which omits frames of inlined functions. Below is an excerpt from the full stack of the crashes. This is the first time I've ever really looked at anything unity related, but perhaps the extra frames will mean somebody more familiar with the API.

0d 000000db`08ddeb00 00007ffc`1e470119     UnityPlayer!GameObject::IsActive+0x50 [c:\buildslave\unity\build\runtime\baseclasses\gameobject.cpp @ 420] 
0e (Inline Function) --------`--------     UnityPlayer!Unity::Component::IsActive+0xe [c:\buildslave\unity\build\runtime\baseclasses\gameobject.h @ 504] 
0f (Inline Function) --------`--------     UnityPlayer!Scripting::IsActiveSceneObject+0x71 [c:\buildslave\unity\build\runtime\scripting\scripting.cpp @ 900] 
10 000000db`08ddeb30 00007ffc`1e504d74     UnityPlayer!Scripting::FindObjectsOfType+0x409 [c:\buildslave\unity\build\runtime\scripting\scripting.cpp @ 945] 
11 (Inline Function) --------`--------     UnityPlayer!UnityEngineObjectBindings::FindObjectsOfType+0x15 [c:\buildslave\unity\build\runtime\export\scripting\unityengineobject.bindings.h @ 15] 
12 000000db`08ddece0 000002c6`1ae780ea     UnityPlayer!Object_CUSTOM_FindObjectsOfType+0x44 [c:\buildslave\unity\build\artifacts\win\core\win64_nondev_m_r\corebindings.gen.cpp @ 40394] 

[KABoissonneault]

No need, I want to handle this one. I just gotta do it before the 1.1 release

[KABoissonneault]

Should be fixed in #2605

[Trabber]

Darn near 6 years later than I last paid attention to this project, all I have to say is that you are epic. Beautiful solution to a whole range of potential issues. I need to make time for gaming again.

…

On Sat., Apr. 6, 2024, 11:42 Kévin Alexandre Boissonneault, < ***@***.***> wrote: Should be fixed in #2605 <#2605> — Reply to this email directly, view it on GitHub <#2355 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AD2U6J54SBDGGTEQBEZG3J3Y4AXYDAVCNFSM5ZFMHTBKU5DIOJSWCZC7NNSXTN2JONZXKZKDN5WW2ZLOOQ5TEMBUGEYTIOBRGIZQ> . You are receiving this because you were mentioned.Message ID: ***@***.***>