View Issue Details

Jump to NotesJump to History
IDProjectCategoryDate SubmittedLast Update
0020899AI War 2Crash/ExceptionJan 27, 2019 7:03 pmApr 18, 2019 1:23 pm
ReporterOvalcircle Assigned ToChris_McElligottPark  
Status closedResolutionfixed 
Product Version0.810 Brace for Cross Planet Attack 
Fixed in VersionBETA 0.850 The Arrival of Fleets 
Summary0020899: Command Execute during frame error - with proposed workaround
Description2 minutes into the save, I got this error. I had to ignore and stop reporting. The debug log is filled with it. I ran the game for about 30-45 minutes. This is just the last minute.
TagsNo tags attached.

Relationships

related to 0020933 closedBadgerBadger Weird error about command that should be executed at frame -1 

Activities

Ovalcircle

Jan 27, 2019 7:03 pm

reporter  

ArcenDebugLog.txt (637,613 bytes)
Hmm.save (3,139,479 bytes)

BadgerBadger

Jan 27, 2019 10:08 pm

manager   ~0050743

Does this error reproduce consistently from the save? ie if you open the game again and reload the save, will the error happen again?

Ovalcircle

Jan 27, 2019 11:25 pm

reporter   ~0050744

It seems it was a one off thing. I tried a few more times and got nothing.
ArcenDebugLog-2.txt (6,124 bytes)    
1/27/2019 10:43:10 PM	Current directory used: C:/Program Files (x86)/Steam/steamapps/common/AI War 2/
Process Count = 0 so PlayerDataDirectory used: C:/Program Files (x86)/Steam/steamapps/common/AI War 2/PlayerData/
1/27/2019 10:43:13 PM	No resolution change was required.
1/27/2019 10:43:13 PM	Applied graphics settings: 
AntialiasingMode:x2
UseSoftParticles:False
BillboardsFaceCameraPosition:False
AnisotropicMode:ForceEnable
TextureQuality:Full
1/27/2019 10:43:13 PM	Applied Framerate Type: 30 FPS (vsync: 0 targetFPS:30)
1/27/2019 10:44:06 PM	ArcenAssetBundleCache.InstantiatedObjects: 777
1/27/2019 10:44:07 PM	Game Version: 0.810
graphicsDeviceType in use: Direct3D11
graphicsDeviceVersion in use: Direct3D 11.0 [level 11.0]
graphicsMultiThreaded: False
graphicsShaderLevel: 50
operatingSystem: Windows 8.1  (6.3.0) 64bit
graphicsDeviceName: Intel(R) HD Graphics 4000
graphicsDeviceID: 358
graphicsDeviceVendor: Intel
graphicsDeviceVendorID: 32902
graphicsDeviceVersion: Direct3D 11.0 [level 11.0]
graphicsMemorySize: 912
maxTextureSize: 16384
npotSupport: Full
processorType: Intel(R) Core(TM) i5-3230M CPU @ 2.60GHz
processorCount: 4
processorFrequency: 2594
systemMemorySize: 8081
supportsImageEffects: True
supportedRenderTargetCount: 8
supportsComputeShaders: True
supportsShadows: True
usesReversedZBuffer: True
1/27/2019 10:44:07 PM	57.9 seconds total load time.

SetDirectoriesToBeUsed (0.8s)
Calculate FInt Sqrt Arrays (0.5s)
Language.Initialize (1.4s)
PresentationLayer.LoadVisualConstants_Early (0.5s)
LoadFinalSFXStuff (13.9s)
ExternalIconDictionaryTable (1.5s)
ArcenUIPrefabTable (2.4s)
ArcenUI.Instance.InitializeOnceOnly (0.3s)
InputActionTypeDataTable (0.3s)
PresentationLayer.LoadVisualConstants_Late (0.4s)
GameSpeedTypeTable (0.3s)
SpaceboxDefinitionTable (1.3s)
PlanetDefinitionTable (4.4s)
GameEntityTypeDataTable.Initialize (4.4s)
GameEntityTypeDataTable.InitVisualBits (20.4s)
SurrogateTableTable (1.3s)
1/27/2019 10:44:08 PM
Hello Steam user 'Ovalcircle'

  at System.Environment.get_StackTrace () [0x00000] in <f826c2584fc94ec19a48a6576640bdc5>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, System.Boolean IncludeStackTrace, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at ArcenGameController.Update () [0x00000] in <2e2dcd579b104a688d65707e5c206ad7>:0 

1/27/2019 10:44:33 PM	Successfully opened host socket
1/27/2019 10:44:55 PM	Post == null on planet Overmars (20).
menu count: 2  menu:BasicGuardianDrawBag drawbag.16 availitems.16  menu:BasicWaveDisallowedGuardianDrawBag drawbag.2 availitems.2
1/27/2019 11:08:19 PM	PLAYER DISCONNECTED 0.0.0.0=>0
1/27/2019 11:13:14 PM	Current directory used: C:/Program Files (x86)/Steam/steamapps/common/AI War 2/
Process Count = 0 so PlayerDataDirectory used: C:/Program Files (x86)/Steam/steamapps/common/AI War 2/PlayerData/
1/27/2019 11:13:14 PM	No resolution change was required.
1/27/2019 11:13:14 PM	Applied graphics settings: 
AntialiasingMode:x2
UseSoftParticles:False
BillboardsFaceCameraPosition:False
AnisotropicMode:ForceEnable
TextureQuality:Full
1/27/2019 11:13:14 PM	Applied Framerate Type: 30 FPS (vsync: 0 targetFPS:30)
1/27/2019 11:13:39 PM	ArcenAssetBundleCache.InstantiatedObjects: 777
1/27/2019 11:13:40 PM	Game Version: 0.810
graphicsDeviceType in use: Direct3D11
graphicsDeviceVersion in use: Direct3D 11.0 [level 11.0]
graphicsMultiThreaded: False
graphicsShaderLevel: 50
operatingSystem: Windows 8.1  (6.3.0) 64bit
graphicsDeviceName: Intel(R) HD Graphics 4000
graphicsDeviceID: 358
graphicsDeviceVendor: Intel
graphicsDeviceVendorID: 32902
graphicsDeviceVersion: Direct3D 11.0 [level 11.0]
graphicsMemorySize: 912
maxTextureSize: 16384
npotSupport: Full
processorType: Intel(R) Core(TM) i5-3230M CPU @ 2.60GHz
processorCount: 4
processorFrequency: 2594
systemMemorySize: 8081
supportsImageEffects: True
supportedRenderTargetCount: 8
supportsComputeShaders: True
supportsShadows: True
usesReversedZBuffer: True
1/27/2019 11:13:40 PM	26.5 seconds total load time.

SetDirectoriesToBeUsed (0.6s)
Calculate FInt Sqrt Arrays (0.4s)
LoadFinalSFXStuff (9.4s)
ExternalIconDictionaryTable (0.3s)
ArcenUIPrefabTable (0.3s)
ArcenUI.Instance.InitializeOnceOnly (0.3s)
InputActionTypeDataTable (0.3s)
PlanetDefinitionTable (0.8s)
GameEntityTypeDataTable.Initialize (0.8s)
GameEntityTypeDataTable.InitVisualBits (8.8s)
SurrogateTableTable (1.3s)
1/27/2019 11:13:41 PM
Hello Steam user 'Ovalcircle'

  at System.Environment.get_StackTrace () [0x00000] in <f826c2584fc94ec19a48a6576640bdc5>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, System.Boolean IncludeStackTrace, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0 
  at ArcenGameController.Update () [0x00000] in <2e2dcd579b104a688d65707e5c206ad7>:0 

1/27/2019 11:15:54 PM	Successfully opened host socket
1/27/2019 11:16:00 PM	Post == null on planet Overmars (20).
menu count: 2  menu:BasicGuardianDrawBag drawbag.16 availitems.16  menu:BasicWaveDisallowedGuardianDrawBag drawbag.2 availitems.2
1/27/2019 11:22:39 PM	PLAYER DISCONNECTED 0.0.0.0=>0
1/27/2019 11:22:39 PM	Successfully opened host socket
1/27/2019 11:23:57 PM	PLAYER DISCONNECTED 0.0.0.0=>0
ArcenDebugLog-2.txt (6,124 bytes)   

RocketAssistedPuffin

Jan 28, 2019 6:46 am

reporter   ~0050747

This was my save originally and I didn't have this error.

BadgerBadger

Jan 29, 2019 12:17 am

manager   ~0050754

Last edited: Jan 29, 2019 11:12 am

 The errors are an endlessly repeating string of

1/27/2019 6:46:07 PM
GAAAH! We have a command we need to execute during frame -1 but it's already frame 266440


GameCommand Details:SetWaiting ToBeQueued:False RelatedEntityIDs:0 RelatedPoints:0 FromActualInputEventOfPlayerID:-1 FromActualInputEventOfPlayerID:-1 FromActualInputEventOfPlayerID:-1 CameFromMultiplayerClientConnectionIndex:-1 ExecuteOnFrameNumber:-1 RelatedEntityType:null RelatedMagnitude:0 PlanetOrderWasIssuedFrom:-1 SentWithToggleSet_SetOrdersForProducedUnits:False RelatedFaction:null RelatedControlGroup:null RelatedPlanetFactionBooleanFlag:None RelatedBool:False RelatedSetup:null RelatedHack:null RelatedString: RelatedEnumValue:0 RelatedSFXItem:null RelatedModdableCommandCode: RelatedIntegers:0 RelatedIntegers2:0 RelatedIntegers3:0 RelatedIntegers4:0 RelatedFInts:0 RelatedBools:0

  at System.Environment.get_StackTrace () [0x00000] in <f826c2584fc94ec19a48a6576640bdc5>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, System.Boolean IncludeStackTrace, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.DebugLogDestination Destination, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0
  at Arcen.Universal.ArcenDebugging.ArcenDebugLog (System.String Message, Arcen.Universal.Verbosity Verbosity) [0x00000] in <371fc104c94a4724860239623ea95520>:0
  at Arcen.AIW2.Core.World_AIW2.OnClient_ExecuteGameCommandsReceivedFromServer (Arcen.AIW2.Core.ArcenSimContext Context) [0x00000] in <02f0aaba903743d5834c5384aaee0536>:0
  at Arcen.AIW2.External.SimPlannerImplementation.DoActualSimStep (System.Boolean& stalledWaitingOnConnections, System.Boolean& mayUpdateVisuals) [0x00000] in <a0a9c5c8aa034a99b8725c689a32e660>:0
  at Arcen.AIW2.Core.Engine_AIW2.ProcessSimStep (System.Boolean& stalledWaitingOnConnections) [0x00000] in <02f0aaba903743d5834c5384aaee0536>:0
  at Arcen.Universal.Engine_Universal.OnUpdateFromMainThread () [0x00000] in <371fc104c94a4724860239623ea95520>:0
  at ArcenGameController.Update () [0x00000] in <2e2dcd579b104a688d65707e5c206ad7>:0

What an odd error. This looks like we're trying to execute an uninitialized GameCommand; all the values look like the default ones; -1s for the ints, nulls for other things and empty lists. The scariest possibility is if we had a double reference to a game command, and another thread wiped out a valid GameCommand while it was in the queue to be sent to the server.


If we can't figure out where this weird command came from, on the error path, I think this is a workaround in World_AWI2.cs:
                    if ( World_AIW2.Instance.CurrentFrameNumber > command.ExecuteOnFrameNumber )
                    {
                        ArcenDebugging.ArcenDebugLog( "GAAAH! We have a command we need to execute during frame " + command.ExecuteOnFrameNumber +
                            " but it's already frame " + World_AIW2.Instance.CurrentFrameNumber + "\n\n" + command.WriteToStringInefficient(), Verbosity.ShowAsError );
                    }
                    else <============ Add this else statement. Possibly also a specific additional check for command.ExecuteOnFrameNumber == -1
                         this.OnClient_GameCommandsThatHaveBeenReceivedFromServerButNotYetExecuted_Backup.Add( command );
                    continue;

I think this will drop the problematic Command; as is I think we are adding the problematic command to the "Screen this command" list each time, causing us to see the error over and over.

Chris_McElligottPark

Apr 18, 2019 1:23 pm

administrator   ~0051083

I'm sure this can still happen, but we'll need new savegames post-0.850. Everything has changed a ton and so any hunting would best be done in a new ticket, I think.

Issue History

Date Modified Username Field Change
Jan 27, 2019 7:03 pm Ovalcircle New Issue
Jan 27, 2019 7:03 pm Ovalcircle File Added: ArcenDebugLog.txt
Jan 27, 2019 7:03 pm Ovalcircle File Added: Hmm.save
Jan 27, 2019 10:08 pm BadgerBadger Note Added: 0050743
Jan 27, 2019 11:25 pm Ovalcircle File Added: ArcenDebugLog-2.txt
Jan 27, 2019 11:25 pm Ovalcircle Note Added: 0050744
Jan 28, 2019 6:46 am RocketAssistedPuffin Note Added: 0050747
Jan 29, 2019 12:17 am BadgerBadger Note Added: 0050754
Jan 29, 2019 12:17 am BadgerBadger Assigned To => Chris_McElligottPark
Jan 29, 2019 12:17 am BadgerBadger Status new => assigned
Jan 29, 2019 11:10 am BadgerBadger Note Edited: 0050754
Jan 29, 2019 11:12 am BadgerBadger Note Edited: 0050754
Feb 7, 2019 11:40 am BadgerBadger Summary Command Execute during frame error => Command Execute during frame error - with proposed workaround
Feb 24, 2019 5:53 pm BadgerBadger Relationship added related to 0020933
Apr 18, 2019 1:23 pm Chris_McElligottPark Status assigned => closed
Apr 18, 2019 1:23 pm Chris_McElligottPark Resolution open => fixed
Apr 18, 2019 1:23 pm Chris_McElligottPark Fixed in Version => BETA 0.850 The Arrival of Fleets
Apr 18, 2019 1:23 pm Chris_McElligottPark Note Added: 0051083