View Issue Details

IDProjectCategoryLast Update
0020899AI War 2[All Projects] Crash/ExceptionFeb 7, 2019 11:40 am
ReporterOvalcircleAssigned Tox4000Bughunter 
Severityminor 
Status assignedResolutionopen 
Product Version0.810 Brace for Cross Planet Attack 
Fixed in Version 
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.

Activities

Ovalcircle

Jan 27, 2019 7:03 pm

reporter  

Hmm.save (3,139,479 bytes)
ArcenDebugLog.txt (637,613 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

developer   ~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

View 3 revisions

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.

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 => x4000Bughunter
Jan 29, 2019 12:17 am BadgerBadger Status new => assigned
Jan 29, 2019 11:10 am BadgerBadger Note Edited: 0050754 View Revisions
Jan 29, 2019 11:12 am BadgerBadger Note Edited: 0050754 View Revisions
Feb 7, 2019 11:40 am BadgerBadger Summary Command Execute during frame error => Command Execute during frame error - with proposed workaround