View Issue Details

Jump to NotesJump to History
IDProjectCategoryDate SubmittedLast Update
0026198AI War 2Crash/ExceptionJan 29, 2022 3:03 amJan 30, 2022 2:20 pm
ReporterApthorpe Assigned ToBadgerBadger  
Severityminor 
Status resolvedResolutionreopened 
Product VersionBeta 3.789 Network Consolidation 
Fixed in VersionBeta 3.790 Defense Against Rogues 
Summary0026198: Sharing debug log due to numerous error popups
DescriptionAs the title says, lots of error popups in this version (and they were also fairly frequent in 3.787 or 3.888. They were most common during larger battles. Obviously start at the 1/28/22 portion for the relevant data.
TagsNo tags attached.

Relationships

related to 0026201 resolvedBadgerBadger Swaping units loops this error 

Activities

Apthorpe

Jan 29, 2022 3:03 am

reporter  

ArcenDebugLog.txt (1,899,282 bytes)

BadgerBadger

Jan 30, 2022 3:05 am

manager   ~0063966

1/28/2022 2:29:25 AM 3.787 SINGLEP Exception in NomadPlanetMoveNotifier.RenderContents at stage 10:System.NullReferenceException: Object reference not set to an instance of an object
  at Arcen.AIW2.External.NomadPlanetMoveNotifier.ContentGetter (Arcen.AIW2.Core.NotifierFillData Data, Arcen.Universal.ArcenUIWrapperedUnityImage Image, Arcen.Universal.ArcenUI_Image+SubImageGroup SubImages, Arcen.Universal.SubTextGroup SubTexts) [0x000ae] in <91dc046ecbef446c989f2d677ec3b947>:0
  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenLog_InnerOnMainThreadOnly (System.String Message, Arcen.Universal.DebugLogDestination Destination, System.Boolean IncludeStackTrace, Arcen.Universal.Verbosity Verbosity, System.DateTime Timestamp) [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.AIW2.External.NomadPlanetMoveNotifier.ContentGetter (Arcen.AIW2.Core.NotifierFillData Data, Arcen.Universal.ArcenUIWrapperedUnityImage Image, Arcen.Universal.ArcenUI_Image+SubImageGroup SubImages, Arcen.Universal.SubTextGroup SubTexts) [0x00000] in <91dc046ecbef446c989f2d677ec3b947>:0
  at Arcen.AIW2.Core.NotificationNonSim.UpdateContentFromVolatile (Arcen.Universal.ArcenUIWrapperedUnityImage Image, Arcen.Universal.ArcenUI_Image+SubImageGroup SubImages, Arcen.Universal.SubTextGroup SubTexts) [0x00000] in <dc4961190d7f44e18b598a6e83af5f9a>:0
  at Arcen.AIW2.External.Window_NotificationsDisplay+btnNotification.UpdateContentFromVolatile (Arcen.Universal.ArcenUIWrapperedUnityImage Image, Arcen.Universal.ArcenUI_Image+SubImageGroup SubImages, Arcen.Universal.SubTextGroup SubTexts) [0x00000] in <91dc046ecbef446c989f2d677ec3b947>:0
  at Arcen.Universal.ArcenUI_ImageButton.OnUpdateVolatileDataFromMainThread () [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.Universal.ArcenUI_Window.OnUpdateVolatileDataFromMainThread () [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.Universal.ArcenUI.OnUpdateVolatileDataFromMainThread () [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.Universal.Engine_Universal.OnUpdateEngineUniversalFromMainThread () [0x00000] in <4621628f1a4f45e2b6b9dc15fc5d0e90>:0
  at Arcen.AIW2.Core.ArcenGameControllerBase.BaseUpdate () [0x00000] in <dc4961190d7f44e18b598a6e83af5f9a>:0
  at ArcenGameController.Update () [0x00000] in <a6cba12c7f0b4f47a1ff69cb43a03552>:0

1/28/2022 10:12:24 PM 3.788 SINGLEP DELAYED44 TID68 List Sort Error: System.ArgumentException: Bogus IComparer:Arcen.Universal.FunctorComparer`1[Arcen.AIW2.Core.GameEntity_Squad]
  at Arcen.Universal.Collections.IntrospectiveSortUtilities.ThrowOrIgnoreBadComparer (System.Object comparer) [0x0001d] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.Universal.Collections.GenericArraySortHelper`1[T].Sort (T[] keys, System.Int32 index, System.Int32 length, Arcen.Universal.Collections.IComparer`1[T] comparer) [0x00012] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.Universal.Collections.ArraySort`1[T].Sort (T[] array, System.Int32 index, System.Int32 length, Arcen.Universal.Collections.IComparer`1[T] comparer) [0x000d3] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.Universal.List`1[T].Sort (System.Comparison`1[T] comparison) [0x0003c] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.List`1[T].Sort (System.Comparison`1[T] comparison) [0x00000] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.AIW2.External.TachyonPlanning.NonClosure_PerTachyonSource (Arcen.AIW2.Core.GameEntity_Squad tachyonEmitterEntity) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.TachyonPlanning.UnrolledDoFor_PerTachyonSource (Arcen.AIW2.Core.PlanetFaction faction) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.TachyonPlanning+<>c__DisplayClass8_0.<Execute>b__0 (Arcen.AIW2.Core.Planet planet) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.Core.Galaxy.DoForPlanetsSingleThread (System.Boolean IncludeDestroyed, Arcen.AIW2.Core.Planet+ProcessorDelegate Processor) [0x00000] in <cd28de615611444382c8e9c8122cfdf8>:0
  at Arcen.AIW2.Core.World_AIW2.DoForPlanetsSingleThread (System.Boolean IncludeDestroyed, Arcen.AIW2.Core.Planet+ProcessorDelegate Processor) [0x00000] in <cd28de615611444382c8e9c8122cfdf8>:0
  at Arcen.AIW2.External.TachyonPlanning.Execute () [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.ArcenShortTermPlanningManager.RunAnExecutionPair_AsABackgroundTask (Arcen.AIW2.External.ArcenShortTermPlanningContext context, System.Boolean shortTermPlanningDebugLog) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.ArcenShortTermPlanningManager+<>c__DisplayClass13_1.<RunAllContextsOnBackgroundThreadsFromMainSimThread>b__0 () [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at System.Threading.Tasks.Task.InnerInvoke () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.Execute () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecutionContextCallback (System.Object obj) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecuteWithThreadLocal (System.Threading.Tasks.Task& currentTaskSlot) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecuteEntry (System.Boolean bPreventDoubleExecution) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0


1/28/2022 11:05:03 PM 3.788 SINGLEP DELAYED63 TID60 Exception in NonClosure_PerTachyonSource at stage 5310:System.IndexOutOfRangeException: Index was outside the bounds of the array.
  at (wrapper stelemref) System.Object.virt_stelemref_class_small_idepth(intptr,object)
  at Arcen.Universal.List`1[T].Add (T item) [0x00056] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.AIW2.External.TachyonPlanning.NonClosure_PerTachyonSource (Arcen.AIW2.Core.GameEntity_Squad tachyonEmitterEntity) [0x00370] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <bbf8afe902cf4b3fb9880bc24b351d85>:0
  at Arcen.AIW2.External.TachyonPlanning.NonClosure_PerTachyonSource (Arcen.AIW2.Core.GameEntity_Squad tachyonEmitterEntity) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.TachyonPlanning.UnrolledDoFor_PerTachyonSource (Arcen.AIW2.Core.PlanetFaction faction) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.TachyonPlanning+<>c__DisplayClass8_0.<Execute>b__0 (Arcen.AIW2.Core.Planet planet) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.Core.Galaxy.DoForPlanetsSingleThread (System.Boolean IncludeDestroyed, Arcen.AIW2.Core.Planet+ProcessorDelegate Processor) [0x00000] in <cd28de615611444382c8e9c8122cfdf8>:0
  at Arcen.AIW2.Core.World_AIW2.DoForPlanetsSingleThread (System.Boolean IncludeDestroyed, Arcen.AIW2.Core.Planet+ProcessorDelegate Processor) [0x00000] in <cd28de615611444382c8e9c8122cfdf8>:0
  at Arcen.AIW2.External.TachyonPlanning.Execute () [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.ArcenShortTermPlanningManager.RunAnExecutionPair_AsABackgroundTask (Arcen.AIW2.External.ArcenShortTermPlanningContext context, System.Boolean shortTermPlanningDebugLog) [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at Arcen.AIW2.External.ArcenShortTermPlanningManager+<>c__DisplayClass13_1.<RunAllContextsOnBackgroundThreadsFromMainSimThread>b__0 () [0x00000] in <0a7b8e2c218e417c8d93bf86c32fc152>:0
  at System.Threading.Tasks.Task.InnerInvoke () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.Execute () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecutionContextCallback (System.Object obj) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecuteWithThreadLocal (System.Threading.Tasks.Task& currentTaskSlot) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.ExecuteEntry (System.Boolean bPreventDoubleExecution) [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading.Tasks.Task.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0

BadgerBadger

Jan 30, 2022 3:25 am

manager   ~0063967

Last edited: Jan 30, 2022 3:50 am

 Working notes. In the commit
    * Fixed a whole cluster of errors that could happen when a savegame was sufficiently large and some background threads were getting double-run.

 The concept of IsCurrentlyWaitingOnThread was added to a number of threads, where the variable to be used to implement a "Only one thread at a time in this critical region" restriction

    public override void Execute()
         {
....
+ if ( IsCurrentlyWaitingOnThread > 0 )
+ return;
...
+ Interlocked.Exchange( ref IsCurrentlyWaitingOnThread, 1 );
<critical region>
+ Interlocked.Exchange( ref IsCurrentlyWaitingOnThread, 0 );

It looks like this is intended to say "When I enter this function, if another thread is doing critical stuff, I should retirm"

Two things I'm concerned about.
First, the check
+ if ( IsCurrentlyWaitingOnThread > 0 )
+ return;
was only added to a couple of the threads. It's missing from a bunch of the other threads changed in that commit, like MovementPlanning and Tachyon Planning. I'm not sure if this was an oversight or there was some reason for it I'm missing.

Second, it seems to me like there's a (potentially very small) race condition where multiple threads threads could successfully pass the if ( IsCurrentlyWaitingOnThread > 0 ) check before any of them gets a chance to call Interlocked.Exchange( ref IsCurrentlyWaitingOnThread, 1 );

I think the calls to
Interlocked.Exchange( ref IsCurrentlyWaitingOnThread, 1 );
need to be
if ( Interlocked.Exchange( ref IsCurrentlyWaitingOnThread, 1 ) != 0 )
    return;
because Exchange returns the previous value in IsCurrentlyWaitingOnThreads

BadgerBadger

Jan 30, 2022 2:20 pm

manager   ~0063974

Fixed

Issue History

Date Modified Username Field Change
Jan 29, 2022 3:03 am Apthorpe New Issue
Jan 29, 2022 3:03 am Apthorpe File Added: ArcenDebugLog.txt
Jan 30, 2022 12:36 am BadgerBadger Assigned To => BadgerBadger
Jan 30, 2022 12:36 am BadgerBadger Status new => closed
Jan 30, 2022 12:36 am BadgerBadger Resolution open => fixed
Jan 30, 2022 12:36 am BadgerBadger Fixed in Version => Beta 3.790 Defense Against Rogues
Jan 30, 2022 3:05 am BadgerBadger Note Added: 0063966
Jan 30, 2022 3:07 am BadgerBadger Status closed => new
Jan 30, 2022 3:07 am BadgerBadger Resolution fixed => reopened
Jan 30, 2022 3:25 am BadgerBadger Note Added: 0063967
Jan 30, 2022 3:26 am BadgerBadger Note Edited: 0063967
Jan 30, 2022 3:50 am BadgerBadger Note Edited: 0063967
Jan 30, 2022 11:35 am BadgerBadger Relationship added related to 0026201
Jan 30, 2022 2:20 pm BadgerBadger Status new => resolved
Jan 30, 2022 2:20 pm BadgerBadger Note Added: 0063974