View Issue Details
| ID | Project | Category | Date Submitted | Last Update | |
|---|---|---|---|---|---|
| 0026605 | AI War 2 | Gameplay Issue | Mar 4, 2022 5:08 pm | Mar 8, 2022 8:30 pm | |
| Reporter | BadgerBadger | Assigned To | Chris_McElligottPark | ||
| Status | resolved | Resolution | fixed | ||
| Product Version | 4.000 Return From The Endless Beta | ||||
| Fixed in Version | 4.002 Macrophage Live! | ||||
| Summary | 0026605: MP 4.000 report | ||||
| Description | I 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 | ||||
| Tags | No tags attached. | ||||
| related to | 0026640 | resolved | Chris_McElligottPark | MP Error Log |
|
|
Are those errors only on the client, and not on the host? |
|
|
Only the client. No errors on the host |
|
|
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. |
| 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 |
