View Issue Details

Jump to NotesJump to History
IDProjectCategoryDate SubmittedLast Update
0026416AI War 2Crash/ExceptionFeb 16, 2022 4:54 pmFeb 17, 2022 10:49 pm
ReporterBadgerBadger Assigned ToChris_McElligottPark  
Status resolvedResolutionfixed 
Product VersionBeta 3.804 Bug Smooshing 
Fixed in VersionBeta 3.805 Bolstering Spire 
Summary0026416: MP errors 3.804
DescriptionFrom today's MP run, with 3.804 on the host and 3.805 (with all my MP fixes from today) on the client. It was about an hour into the game (with a number of factions on) when i hit a host problem an then a ton of client problems

2/16/2022 2:49:02 PM 3.804 HOST DELAYED16 TID6 Error A! Called CreateExternalBaseInfo<Arcen.AIW2.External.ScourgePerUnitBaseInfo>() when BaseInfo was actually a different type, Arcen.AIW2.External.SappersPerUnitBaseInfo on Neophyte
  at System.Environment.get_StackTrace () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <202e62c518b24a6aa82c1650807a9296>:0
  at Arcen.AIW2.Core.GameEntity_Squad.CreateExternalBaseInfo[T] (System.String BaseInfoSourceName) [0x00000] in <5170314c3d3445ad976b1cc49a9314d5>:0
  at Arcen.AIW2.External.ScourgeFactionDeepInfo.HandleSpawning_OnMainSimOnly (Arcen.AIW2.Core.Faction faction, Arcen.AIW2.Core.ArcenHostOnlySimContext Context, Arcen.AIW2.Core.GameEntity_Squad entity) [0x00000] in <a7937b07c0104ee8b53fe90eee2d4dcb>:0
  at Arcen.AIW2.External.ScourgeFactionDeepInfo+<>c__DisplayClass7_0.<DoPerSecondLogic_Stage3Main_OnMainThreadAndPartOfSim_HostOnly>b__1 (Arcen.AIW2.Core.GameEntity_Squad entity) [0x00000] in <a7937b07c0104ee8b53fe90eee2d4dcb>:0
  at Arcen.AIW2.Core.EntityCollection.DoForEntities (System.String Tag, Arcen.AIW2.Core.GameEntity_Squad+ProcessorDelegate Processor) [0x00000] in <5170314c3d3445ad976b1cc49a9314d5>:0
  at Arcen.AIW2.Core.Faction.DoForEntities (System.String Tag, Arcen.AIW2.Core.GameEntity_Squad+ProcessorDelegate Processor) [0x00000] in <5170314c3d3445ad976b1cc49a9314d5>:0
  at Arcen.AIW2.External.ScourgeFactionDeepInfo.DoPerSecondLogic_Stage3Main_OnMainThreadAndPartOfSim_HostOnly (Arcen.AIW2.Core.ArcenHostOnlySimContext Context) [0x00000] in <a7937b07c0104ee8b53fe90eee2d4dcb>:0
  at Arcen.AIW2.Core.Faction.Safe_DeepInfo_DoPerSecondLogic_Stage3Main_OnMainThreadAndPartOfSim_HostOnly (Arcen.AIW2.Core.ArcenHostOnlySimContext Context) [0x00000] in <5170314c3d3445ad976b1cc49a9314d5>:0
  at Arcen.AIW2.External.EntitySimLogicImplementation_BaseInfo+<>c__DisplayClass110_0.<DoWorldSecondLogic_FromSimBGThread>b__4 (Arcen.AIW2.Core.Faction faction) [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.Core.World_AIW2.DoForFactions (Arcen.AIW2.Core.Faction+ProcessorDelegate Processor) [0x00000] in <5170314c3d3445ad976b1cc49a9314d5>:0
  at Arcen.AIW2.External.EntitySimLogicImplementation_BaseInfo.DoWorldSecondLogic_FromSimBGThread (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.External.EntitySimLogicImplementation_BaseInfo.DoWorld_PerStep_TimeKeeping (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.External.EntitySimLogicImplementation_BaseInfo.DoWorldStepLogic_ClientOrHost_FromSimBGThread (Arcen.AIW2.Core.ArcenClientOrHostSimContextCore Context) [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.External.SimExecution.Execute () [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.External.ArcenClientOrHostSimPlanningContext.BackgroundThreadRunHandler (System.Single SuicidesAfterTime, System.Boolean FailSilentlyIfNotFinishedYet) [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.AIW2.External.ArcenClientOrHostSimPlanningContext+<>c__DisplayClass15_0.<RunOnBackgroundThread>b__0 () [0x00000] in <889c1884bbe44839ba905fd17ce877c3>:0
  at Arcen.Universal.ArcenThreading+<>c__DisplayClass11_0.<RunTaskOnBackgroundThread>b__0 () [0x00000] in <202e62c518b24a6aa82c1650807a9296>: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
  at System.Threading.ThreadPoolWorkQueue.Dispatch () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0
  at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () [0x00000] in <695d1cc93cca45069c528c15c9fdd749>:0

and on the client
2/16/2022 2:35:31 PM 3.804 CLIENT Multiplayer Connection Time Taken: Sending_Profile_Name_Expansions_And_Mods - 2.1s
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED7 TID41 Canary code mismatch at EntityCanaryPostSys ('' instead of 'P'). Code above it is the real problem.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED8 TID41 Canary code mismatch at EntityCanaryGP ('' instead of 'GP'). Code above it is the real problem.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED9 TID41 GameEntity_Squad deserialization error at stage 12000 from serialized version 3.804 loading into new version 3.804, error: System.Ex
ception: Tried to read more bits from a deserialization buffer than we had! Requested byte index to pull bit from was 116, but the number of bytes in this buffer was only 116 (Chunk Index
 was 0 out of 1 chunks)
  at Arcen.Universal.ArcenDeserializationBufferModern.GetNextBit () [0x0018d] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBuff
erModern.cs:1174
  at Arcen.Universal.ArcenDeserializationBufferModern.GetBits_InnerHelperUltraEfficient (Arcen.Universal.UltraEfficientStyleData ueStyleData) [0x00072] in /data/Games/arcengames_aiw-ultra
/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenSerializationUltraEfficientExtensions.cs:1689
  at Arcen.Universal.ArcenDeserializationBufferModern.ReadIntUltraEfficient (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.UltraEfficientStyle UEStyle, System.String FieldNameForE
rrors) [0x000d3] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenSerializationUltraEfficientExtensions.cs:1574
  at Arcen.AIW2.Core.GameEntity_Squad.DeserializeSquadIntoSelf (Arcen.Universal.SerMetaData MetaData, System.Int32 primaryKeyID, Arcen.AIW2.Core.GameEntityTypeData typeData, Arcen.AIW2.Co
re.Planet NewPlanet, Arcen.Universal.ArcenDeserializationBuffer Buffer, System.Boolean HideErrors, System.Boolean IsLoadingTemplate, Arcen.Universal.SerializationCommandType Serialization
CmdType, Arcen.AIW2.Core.PlanetFaction NewPlanetFaction) [0x010b0] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/GameEntity/GameEntity_Squad.cs:2060
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED10 TID41 Skipping read of canary 'PreExternal' because HasHadExceptionThatShouldHaltAllFurtherReads.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED11 TID41 DeserializeExternalSquadData error at stage 0 from serialized version 3.804 loading into new version 3.804, error: System.Exception: Tried to read more bits from a deserialization buffer than we had! Requested byte index to pull bit from was 116, but the number of bytes in this buffer was only 116 (Chunk Index was 0 out of 1 chunks)
  at Arcen.Universal.ArcenDeserializationBufferModern.GetNextBit () [0x0018d] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1174
  at Arcen.Universal.ArcenDeserializationBufferModern.TryReadBool (System.Boolean& WasSuccessful, System.Boolean ThrowExceptionOnFailure) [0x00002] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:489
  at Arcen.Universal.ArcenDeserializationBufferModern.ReadBool (Arcen.Universal.SerMetaData MetaData, System.String FieldNameForErrors) [0x0009e] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:471
  at Arcen.AIW2.Core.GameEntity_Squad.DeserializeExternalSquadData (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer, Arcen.Universal.SerializationCommandType SerializationCmdType, System.String& DebugLastExternalUnitTypeData) [0x0000b] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/GameEntity/GameEntity_Squad.cs:2298
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED12 TID41 Skipping read of canary 'PostExternal' because HasHadExceptionThatShouldHaltAllFurtherReads.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED13 TID41 Theseus failure: numberOfMainDeserializations: 1 numberOfExternalDeserializations: 1 numberOfCanary6Fails: 1 numberOfCanary6Successes: 0 lastExternalUnitTypeData
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED14 TID41 Skipping read of canary 'InternalCanary' because HasHadExceptionThatShouldHaltAllFurtherReads.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED15 TID41 Not fatal - just a warning: Client_AcceptDivergenceDataFromHost: Null planet found at index: -1. Abandoning rest of sync fix data from this cycle.


2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED69 TID41 Not fatal - just a warning: Client_AcceptDivergenceDataFromHost: Null planet found at index: -1. Abandoning rest of sync fix data from this cycle.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED70 TID41 Skipping read of canary 'CanaryCode' because HasHadExceptionThatShouldHaltAllFurtherReads.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED71 TID41 Faction deserialization error at stage 14200 from serialized version 3.804 loading into new version 3.804, error: System.Exception: Tried to read more bits from a deserialization buffer than we had! Requested byte index to pull bit from was 1432, but the number of bytes in this buffer was only 1432 (Chunk Index was 0 out of 1 chunks)
  at Arcen.Universal.ArcenDeserializationBufferModern.GetNextBit () [0x0018d] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1174
  at Arcen.Universal.ArcenDeserializationBufferModern.GetBits_InnerHelper32 (Arcen.Universal.ReadStyle RStyle) [0x00002] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1026
  at Arcen.Universal.ArcenDeserializationBufferModern.ReadInt32 (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ReadStyle RStyle, System.String FieldNameForErrors) [0x000d2] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:287
  at Arcen.AIW2.Core.VassalMission.DeserializeFrom (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer) [0x0019e] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/WorldExtras/VassalMission.cs:284
  at Arcen.AIW2.Core.VassalMission.Create (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer) [0x0000f] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/WorldExtras/VassalMission.cs:216
  at Arcen.AIW2.Core.Faction.DeserializeFactionIntoSelf (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer, Arcen.AIW2.Core.ConfigurationForFaction Config, System.Boolean IsLoadingForTemplate, Arcen.Universal.SerializationCommandType SerializationCmdType) [0x009ab] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/GameState/Faction/Faction.cs:1053
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED72 TID41 Error in Client_AcceptUltraFrequentSyncDataThatJustOverrides, debugStage 700: System.Exception: Tried to read more bits from a deserialization buffer than we had! Requested byte index to pull bit from was 1432, but the number of bytes in this buffer was only 1432 (Chunk Index was 0 out of 1 chunks)
  at Arcen.Universal.ArcenDeserializationBufferModern.GetNextBit () [0x0018d] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1174
  at Arcen.Universal.ArcenDeserializationBufferModern.GetBits_InnerHelper16 (Arcen.Universal.ReadStyle RStyle) [0x00002] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1074
  at Arcen.Universal.ArcenDeserializationBufferModern.ReadInt16 (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ReadStyle RStyle, System.String FieldNameForErrors) [0x000d2] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:247
  at AIWar2NetworkSync.Client_AcceptUltraFrequentSyncDataThatJustOverrides (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer buffer) [0x0009f] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/AIWar2NetworkSync.cs:1998
  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 AIWar2NetworkSync.Client_AcceptUltraFrequentSyncDataThatJustOverrides (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer buffer) [0x001ef] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/AIWar2NetworkSync.cs:2028
  at Arcen.AIW2.Core.AIWar2Networking.HandleMessage (System.Int64 UniqueMessageIDFromSender, System.Boolean IsFromSelfWithoutNetwork, System.UInt32 senderNetworkID, Arcen.Universal.ArcenNetworkMessageType CoreNetworkMessageType, Arcen.Universal.ArcenDeserializationBuffer buffer) [0x00205] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/Networking/AIWar2Networking.cs:317


2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED240 TID28 Not fatal - just a warning: Client_AcceptDivergenceDataFromHost: Null planet found at index: -1. Abandoning rest of sync fix data
 from this cycle.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED241 TID28 Skipping read of canary 'CanaryCode' because HasHadExceptionThatShouldHaltAllFurtherReads.
2/16/2022 2:48:58 PM 3.804 CLIENT DELAYED242 TID28 Faction deserialization error at stage 14200 from serialized version 3.804 loading into new version 3.804, error: System.Exception
: Tried to read more bits from a deserialization buffer than we had! Requested byte index to pull bit from was 323, but the number of bytes in this buffer was only 323 (Chunk Index was 0
out of 1 chunks)
  at Arcen.Universal.ArcenDeserializationBufferModern.GetNextBit () [0x0018d] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBuff
erModern.cs:1174
  at Arcen.Universal.ArcenDeserializationBufferModern.GetBits_InnerHelper32 (Arcen.Universal.ReadStyle RStyle) [0x00090] in /data/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversa
l/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:1054
  at Arcen.Universal.ArcenDeserializationBufferModern.ReadInt32 (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ReadStyle RStyle, System.String FieldNameForErrors) [0x000d2] in /da
ta/Games/arcengames_aiw-ultra/CodeCrossProject/ArcenUniversal/src/ArcenBuffers/ArcenDeserializationBufferModern.cs:287
  at Arcen.AIW2.Core.VassalMission.DeserializeFrom (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer) [0x0019e] in /data/Games/arcengames_aiw-ultra/
CodeMain/ArcenAIW2Core/src/Logic/GameState/WorldExtras/VassalMission.cs:284
  at Arcen.AIW2.Core.VassalMission.Create (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer) [0x0000f] in /data/Games/arcengames_aiw-ultra/CodeMain/
ArcenAIW2Core/src/Logic/GameState/WorldExtras/VassalMission.cs:216
  at Arcen.AIW2.Core.Faction.DeserializeFactionIntoSelf (Arcen.Universal.SerMetaData MetaData, Arcen.Universal.ArcenDeserializationBuffer Buffer, Arcen.AIW2.Core.ConfigurationForFaction C
onfig, System.Boolean IsLoadingForTemplate, Arcen.Universal.SerializationCommandType SerializationCmdType) [0x009ab] in /data/Games/arcengames_aiw-ultra/CodeMain/ArcenAIW2Core/src/Logic/G
ameState/Faction/Faction.cs:1053

And a bunch of other errors too. I'm just going to attach the client log
TagsNo tags attached.

Activities

BadgerBadger

Feb 16, 2022 4:54 pm

manager  

debuglog.txt (3,031,350 bytes)

Chris_McElligottPark

Feb 17, 2022 10:43 pm

administrator   ~0064581

Thanks!

* The "Error A! Called CreateExternalBaseInfo<Whatever>() when BaseInfo was actually a different type" error is now just a silent warning. It should self-correct, and it's rare, but it would be nice to see these from logs, regardless.

Chris_McElligottPark

Feb 17, 2022 10:49 pm

administrator   ~0064582

Okay, other than that one bug, everything else was a matter of the game overrunning how much it was supposed to read. It was doing this in two different code paths, and so I strongly suspect that serialization changed between your non-steam version and the steam version, and that this is the source of your issues of that sort. I can't be sure, but essentially there's just one error here, and that's "read more than we were supposed to," and it's happening before we get to canaries in a couple of spots. Given how you described how you were running MP yesterday, this seems like a very likely culprit.

Which is excellent if so, because that means that this was a very clean MP session, and it should be resolved now that the steam version is getting an update!

Issue History

Date Modified Username Field Change
Feb 16, 2022 4:54 pm BadgerBadger New Issue
Feb 16, 2022 4:54 pm BadgerBadger Status new => assigned
Feb 16, 2022 4:54 pm BadgerBadger Assigned To => Chris_McElligottPark
Feb 16, 2022 4:54 pm BadgerBadger File Added: debuglog.txt
Feb 17, 2022 10:43 pm Chris_McElligottPark Note Added: 0064581
Feb 17, 2022 10:49 pm Chris_McElligottPark Status assigned => resolved
Feb 17, 2022 10:49 pm Chris_McElligottPark Resolution open => fixed
Feb 17, 2022 10:49 pm Chris_McElligottPark Fixed in Version => Beta 3.805 Bolstering Spire
Feb 17, 2022 10:49 pm Chris_McElligottPark Note Added: 0064582