View Issue Details

Jump to NotesJump to History
IDProjectCategoryDate SubmittedLast Update
0026605AI War 2Gameplay IssueMar 4, 2022 5:08 pmMar 8, 2022 8:30 pm
ReporterBadgerBadger Assigned ToChris_McElligottPark  
Status resolvedResolutionfixed 
Product Version4.000 Return From The Endless Beta 
Fixed in Version4.002 Macrophage Live! 
Summary0026605: MP 4.000 report
DescriptionI loaded my save from https://bugtracker.arcengames.com/view.php?id=26592 and rapidly hit a number of similar errors:


3/4/2022 3:05:46 PM 4.000 CLIENT DELAYED7 TID49 command.RelatedPoints.Count < 1 in GameCommand_MoveManyToOnePoint!
GameCommand Details:MoveManyToOnePoint_FireteamEscort
  RelatedFactionIndex:-1

  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00042] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/Debug/ArcenDebugging.cs:242
  at Arcen.AIW2.External.GameCommand_MoveManyToOnePoint.Execute (Arcen.AIW2.Core.GameCommand command, Arcen.AIW2.Core.ArcenClientOrHostSimContextCore context) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.GameCommand.Execute (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00061] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/GameCommand.cs:423
  at Arcen.AIW2.Core.World_AIW2.OnClientOrHost_ExecuteGameCommandsThatWereScheduled (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00193] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/World_AIW2.cs:4133
  at Arcen.AIW2.External.SimPlannerImplementation.ProcessCoreLogicForArbitraryFrameOnMainThread (System.Boolean& stalledWaitingOnConnections, System.Boolean& mayUpdateVisuals, System.String& reasonForNoVisualUpdates) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.Engine_AIW2.<ProcessArbitraryFrameOnMainThread>m__F () [0x00016] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Engine_AIW2.cs:1502
  at Arcen.Universal.ArcenThreading+<RunTaskOnBackgroundThread>c__AnonStorey0.<>m__0 () [0x00035] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/ArcenThreading.cs:135
  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
  at System.Threading.ThreadPoolWorkQueue.Dispatch () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0

3/4/2022 3:05:51 PM 4.000 CLIENT DELAYED8 TID8 OtherObject: Not fatal - just a warning: Client_TrulyProcessFastBlastDataOfCreatedObjects: Null faction found at index: -1. Abandoning rest of sync data from this cycle.
3/4/2022 3:05:54 PM 4.000 CLIENT DELAYED9 TID8 command.RelatedPoints.Count < 1 in GameCommand_MoveManyToOnePoint!
GameCommand Details:MoveManyToOnePoint_FireteamEscort
  RelatedFactionIndex:-1

  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00042] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/Debug/ArcenDebugging.cs:242
  at Arcen.AIW2.External.GameCommand_MoveManyToOnePoint.Execute (Arcen.AIW2.Core.GameCommand command, Arcen.AIW2.Core.ArcenClientOrHostSimContextCore context) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.GameCommand.Execute (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00061] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/GameCommand.cs:423
  at Arcen.AIW2.Core.World_AIW2.OnClientOrHost_ExecuteGameCommandsThatWereScheduled (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00116] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/World_AIW2.cs:4111
  at Arcen.AIW2.External.SimPlannerImplementation.ProcessCoreLogicForArbitraryFrameOnMainThread (System.Boolean& stalledWaitingOnConnections, System.Boolean& mayUpdateVisuals, System.String& reasonForNoVisualUpdates) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.Engine_AIW2.<ProcessArbitraryFrameOnMainThread>m__F () [0x00016] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Engine_AIW2.cs:1502
  at Arcen.Universal.ArcenThreading+<RunTaskOnBackgroundThread>c__AnonStorey0.<>m__0 () [0x00035] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/ArcenThreading.cs:135
  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
  at System.Threading.ThreadPoolWorkQueue.Dispatch () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0


and

3/4/2022 3:06:05 PM 4.000 CLIENT DELAYED21 TID19 command.RelatedPoints.Count < 1 in GameCommand_MoveManyToOnePoint!
GameCommand Details:MoveManyToOnePoint_NPCRandomMetalSpot
  RelatedFactionIndex:-1

  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00042] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/Debug/ArcenDebugging.cs:242
  at Arcen.AIW2.External.GameCommand_MoveManyToOnePoint.Execute (Arcen.AIW2.Core.GameCommand command, Arcen.AIW2.Core.ArcenClientOrHostSimContextCore context) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.GameCommand.Execute (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00061] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/GameCommand.cs:423
  at Arcen.AIW2.Core.World_AIW2.OnClientOrHost_ExecuteGameCommandsThatWereScheduled (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00193] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/World_AIW2.cs:4133
  at Arcen.AIW2.External.SimPlannerImplementation.ProcessCoreLogicForArbitraryFrameOnMainThread (System.Boolean& stalledWaitingOnConnections, System.Boolean& mayUpdateVisuals, System.String& reasonForNoVisualUpdates) [0x00000] in <2c686a3c28fe48309760bdb8024dc7ab>:0
  at Arcen.AIW2.Core.Engine_AIW2.<ProcessArbitraryFrameOnMainThread>m__F () [0x00016] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Engine_AIW2.cs:1502
  at Arcen.Universal.ArcenThreading+<RunTaskOnBackgroundThread>c__AnonStorey0.<>m__0 () [0x00035] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/UtilityLibraries/ArcenThreading.cs:135
  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
  at System.Threading.ThreadPoolWorkQueue.Dispatch () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0

These issues happened very frequently, and at the minimum badly clutter the log
TagsNo tags attached.

Relationships

related to 0026640 resolvedChris_McElligottPark MP Error Log 

Activities

Chris_McElligottPark

Mar 4, 2022 5:38 pm

administrator   ~0065129

Are those errors only on the client, and not on the host?

BadgerBadger

Mar 4, 2022 7:29 pm

manager   ~0065130

Only the client. No errors on the host

Chris_McElligottPark

Mar 8, 2022 8:30 pm

administrator   ~0065253

Thanks!

* Fixed an issue where GameCommands were using a custom ConcurrentQueue solution instead of an actual proper pool, and that was probably leading to some game commands getting added in twice (there was no protection against that, unlike in the proper pooling solutions), and thus this is likely the culprit for some of the deserialization issues that we were seeing on MP clients. It's probable that this was also causing other issues.
** As part of this, I consolidated things to one pool rather than one pool per game command type (this was something that was required based on the nature of the pool initializer methods). A side effect of this is lower memory usage from commands in general, and fewer of them in existence during the game. Originally I had split it because I was worried about contention between multiple threads, but we're really an order of magnitude away from having to worry about that, which is good. A lot of those original design choices were because I made the changes here very early on into the refactor before I had truly tested out every aspect of performance and behavior that came over the 8 months after that. And then I just never noticed that this was a bit off.

Issue History

Date Modified Username Field Change
Mar 4, 2022 5:08 pm BadgerBadger New Issue
Mar 4, 2022 5:08 pm BadgerBadger Status new => assigned
Mar 4, 2022 5:08 pm BadgerBadger Assigned To => Chris_McElligottPark
Mar 4, 2022 5:09 pm BadgerBadger Description Updated
Mar 4, 2022 5:38 pm Chris_McElligottPark Note Added: 0065129
Mar 4, 2022 7:29 pm BadgerBadger Note Added: 0065130
Mar 7, 2022 11:32 am Chris_McElligottPark Relationship added related to 0026640
Mar 8, 2022 8:30 pm Chris_McElligottPark Status assigned => resolved
Mar 8, 2022 8:30 pm Chris_McElligottPark Resolution open => fixed
Mar 8, 2022 8:30 pm Chris_McElligottPark Fixed in Version => 4.002 Macrophage Live!
Mar 8, 2022 8:30 pm Chris_McElligottPark Note Added: 0065253