[2.0.7] crash in effect triggers (LuaEventDispatcher::checkEventsAreAllowed)

ahicks · Post by **ahicks** » Tue Oct 22, 2024 10:19 pm

So...this one is fun. I don't know what causes it. I have seen it on a new game. I have seen it in multiple saves. It just....happens. Only fix is to not use effect triggers as far as I can tell. Since my other post, I modified our code to just throw the event's important information out of the event and into a worker queue so interactions with the engine no longer happen in that code path at all. Log:

Code: Select all

   0.001 2024-10-22 15:02:43; Factorio 2.0.7 (build 79385, win64, full)
   0.001 Operating system: Windows 10 (build 19045) 
   0.002 Program arguments: "C:\projects\in_progress\factorio_access\factorio\bin\x64\factorio.exe" "-c" "C:\projects\in_progress\factorio_access\factorio\config\config.ini" "--load-game" "C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip" 
   0.002 Config path: C:/projects/in_progress/factorio_access/factorio/config/config.ini
   0.002 Read data path: C:/projects/in_progress/factorio_access/factorio/data
   0.002 Write data path: C:/projects/in_progress/factorio_access/factorio [130879/976144MB]
   0.002 Binaries path: C:/projects/in_progress/factorio_access/factorio/bin
   0.041 System info: [CPU: Intel(R) Core(TM) i7-8700 CPU @ 3.20GHz, 12 cores, RAM: 16057/65474 MB, page: 16534/75202 MB, virtual: 4266/134217727 MB, extended virtual: 0 MB]
   0.062 Memory info:
   0.062  [0]: 04CD F4-2666C19-16GIS 16384 MB 2400 MHz 1.2 v
   0.062  [1]: 04CD F4-2666C19-16GIS 16384 MB 2400 MHz 1.2 v
   0.062  [2]: 04CD F4-2666C19-16GIS 16384 MB 2400 MHz 1.2 v
   0.062  [3]: 04CD F4-2666C19-16GIS 16384 MB 2400 MHz 1.2 v
   0.067 Display options: [FullScreen: true] [VSync: true] [UIScale: automatic (100.0%)] [Native DPI: true] [Screen: 255] [Special: lmw] [Lang: en]
   0.209 Video driver: windows
   0.209 Available displays: 1
   0.209  [0]: \\.\DISPLAY1 - NVIDIA GeForce RTX 2060 {0x05, [0,0], 1920x1080, 32bit, 60Hz}
   0.250 [Direct3D11] Display: 0, Output: 0, DisplayAdapter: 0, RenderingAdapter: 0; d3dcompiler_47.dll
   0.425 Initialised Direct3D[0]: NVIDIA GeForce RTX 2060; id: 10de-1f08; driver: nvldumdx.dll 32.0.15.6094
   0.425   D3D Feature Level: 11.1, DXGI 1.5+, SwapChain: 3,flip-discard,-,-,-,none
   0.425   [Local Video Memory] Budget: 5186MB, CurrentUsage: 6MB, Reservation: 0/2721MB
   0.425   [Non-Local Vid.Mem.] Budget: 31969MB, CurrentUsage: 0MB, Reservation: 0/16112MB
   0.425   Tiled resources: Tier 2
   0.425   Unified Memory Architecture: No
   0.425   BGR 565 Supported: Yes
   0.425   MaximumFrameLatency: 3, GPUThreadPriority: 0
   0.425 Graphics settings preset: very-high
   0.425   Dedicated video memory size 5954 MB
   0.500 Desktop composition is active.
   0.500 Graphics options: [Graphics quality: high] [Video memory usage: all] [DXT: high-quality]
   0.500                   [Max threads (load/render): 32/12] [Max texture size: 0] [Tex.Stream.: false] [Rotation quality: normal] [Other: STDCWT] [B:0,C:0,S:100]
   0.534 [Audio] Driver:wasapi, Device:Default device, Depth:16, Channels:2, Frequency:44100
   0.669 Logitech LED Controller initialized.
   0.670 Error SteelSeriesGameSenseWindowsController.cpp:118: Failed to start SteelSeries GameSense. Error when processing coreProps.json file: GameSense address is empty
   0.712 Info ModManager.cpp:434: FeatureFlag expansion-shaders = false
   0.712 Info ModManager.cpp:434: FeatureFlag freezing = false
   0.712 Info ModManager.cpp:434: FeatureFlag quality = false
   0.712 Info ModManager.cpp:434: FeatureFlag rail-bridges = false
   0.712 Info ModManager.cpp:434: FeatureFlag segmented-units = false
   0.712 Info ModManager.cpp:434: FeatureFlag space-travel = false
   0.712 Info ModManager.cpp:434: FeatureFlag spoiling = false
   0.715 Loading mod settings FactorioAccess 0.15.1 (settings-updates.lua)
   0.717 Loading mod core 0.0.0 (data.lua)
   0.755 Loading mod base 2.0.7 (data.lua)
   1.317 Loading mod FactorioAccess 0.15.1 (data.lua)
   1.335 Loading mod base 2.0.7 (data-updates.lua)
   1.348 Loading mod FactorioAccess 0.15.1 (data-updates.lua)
   1.489 Checksum for core: 649243273
   1.489 Checksum of base: 2653731351
   1.489 Checksum of FactorioAccess: 4233049199
   1.738 Prototype list checksum: 1538945158
   1.774 Loading sounds...
   2.099 Info PlayerData.cpp:66: Local player-data.json available, timestamp 1729634563
   2.099 Info PlayerData.cpp:73: Cloud player-data.json unavailable
   2.424 Initial atlas bitmap size is 16384
   2.519 Created an atlas bitmap (size 16384x16384) [none]
   2.521 Created an atlas bitmap (size 16384x12652) [none]
   2.521 Created an atlas bitmap (size 8192x4352) [decal]
   2.522 Created an atlas bitmap (size 16384x7616) [low-object]
   2.523 Created an atlas bitmap (size 16384x11340) [corpse-decay]
   2.524 Created an atlas bitmap (size 8192x5616) [mipmap, linear-minification, linear-magnification, linear-mip-level]
   2.524 Created an atlas bitmap (size 16384x6288) [terrain, mipmap, linear-minification, linear-mip-level]
   2.525 Created an atlas bitmap (size 4096x2960) [terrain-effect-map, mipmap, linear-minification, linear-mip-level]
   2.525 Created an atlas bitmap (size 4096x1792) [smoke, mipmap, linear-minification, linear-magnification]
   2.525 Created an atlas bitmap (size 4096x3088) [mipmap]
   2.525 Created an atlas bitmap (size 8192x2704) [icon, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level]
   2.526 Created an atlas bitmap (size 8192x5168) [alpha-mask]
   2.549 Created an atlas bitmap (size 16384x16364) [shadow, linear-magnification, alpha-mask]
   2.550 Created an atlas bitmap (size 16384x3964) [shadow, linear-magnification, alpha-mask]
   2.550 Created an atlas bitmap (size 8192x2352) [shadow, mipmap, linear-magnification, alpha-mask]
   2.550 Created an atlas bitmap (size 2048x368) [icon-background, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level, ]
   3.426 Loading 3D bitmaps.
   3.434 Texture processor created (2048). GPU accelerated compression Supported: yes, Enabled: yes/yes. Test passed. YCoCgDXT PSNR: 35.83, BC3 PSNR: 33.82
   3.452 Parallel sprite loader initialized (threads: 11, bitmaps: 4573)
  12.159 Sprites loaded
  12.183 Generated mipmaps (4) for atlas [3] of size 16384x7616   
  12.195 Generated mipmaps (3) for atlas [5] of size 8192x5616   
  12.206 Generated mipmaps (3) for atlas [6] of size 16384x6288   
  12.218 Generated mipmaps (3) for atlas [7] of size 4096x2960   
  12.229 Generated mipmaps (3) for atlas [8] of size 4096x1792   
  12.267 Generated mipmaps (3) for atlas [9] of size 4096x3088   
  12.279 Generated mipmaps (5) for atlas [10] of size 8192x2704   
  12.291 Generated mipmaps (3) for atlas [14] of size 8192x2352   
  12.313 Custom mipmaps uploaded (2123)
  12.319 Error ControlSettings.cpp:1014: decrease-inventory-bar-by-100 (custom-input): unknown alternative_key_sequence: CTRL + DOWN
  12.319 Error ControlSettings.cpp:1014: decrease-train-wait-times-by-60 (custom-input): unknown alternative_key_sequence: CTRL + DOWN
  12.319 Error ControlSettings.cpp:1014: increase-inventory-bar-by-100 (custom-input): unknown alternative_key_sequence: CTRL + UP
  12.319 Error ControlSettings.cpp:1014: increase-train-wait-times-by-60 (custom-input): unknown alternative_key_sequence: CTRL + UP
  12.324 Custom inputs active: 228
  12.398 Factorio initialised
  12.398 Discord overlay detected (DiscordHook64.dll)
  12.406 Loading map C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip: 1493022 bytes.
  12.456 Loading level.dat: 988043 bytes.
  12.460 Info Scenario.cpp:178: Map version 2.0.7-0
  12.477 Loading script.dat: 3666 bytes.
  12.487 Checksum for script __level__/control.lua: 3780939624
  12.702 Checksum for script __FactorioAccess__/control.lua: 718779450
  16.711 Error MainLoop.cpp:1429: Exception at tick 238: The mod Factorio Access Mod (0.15.1) caused a non-recoverable error.
Please report this error to the mod author.

Error while running event FactorioAccess::open-inventory (ID 333)
LuaGameScript doesn't contain key get_filtered_recipe_prototypes.
stack traceback:
	[C]: in function '__index'
	__FactorioAccess__/scripts/crafting.lua:17: in function 'get_recipes'
	__FactorioAccess__/control.lua:3610: in function 'open_player_inventory'
	__FactorioAccess__/control.lua:3593: in function <__FactorioAccess__/control.lua:3586>
 114.767 Loading map C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip: 1493022 bytes.
 114.817 Loading level.dat: 988043 bytes.
 114.820 Info Scenario.cpp:178: Map version 2.0.7-0
 114.838 Loading script.dat: 3666 bytes.
 114.848 Checksum for script __level__/control.lua: 3780939624
 115.029 Checksum for script __FactorioAccess__/control.lua: 3187685951
 120.144 Error MainLoop.cpp:1429: Exception at tick 306: The mod Factorio Access Mod (0.15.1) caused a non-recoverable error.
Please report this error to the mod author.

Error while running event FactorioAccess::switch-menu-or-gun (ID 418)
__FactorioAccess__/control.lua:4103: attempt to index local 'ammo_inv' (a nil value)
stack traceback:
	__FactorioAccess__/control.lua:4103: in function 'swap_weapon_forward'
	__FactorioAccess__/control.lua:3915: in function <__FactorioAccess__/control.lua:3785>
 212.538 Loading map C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip: 1493022 bytes.
 212.616 Loading level.dat: 988043 bytes.
 212.620 Info Scenario.cpp:178: Map version 2.0.7-0
 212.638 Loading script.dat: 3666 bytes.
 212.649 Checksum for script __level__/control.lua: 3780939624
 212.829 Checksum for script __FactorioAccess__/control.lua: 3433998258
 220.277 Error MainLoop.cpp:1429: Exception at tick 446: The mod Factorio Access Mod (0.15.1) caused a non-recoverable error.
Please report this error to the mod author.

Error while running event FactorioAccess::open-inventory (ID 333)
__FactorioAccess__/control.lua:3607: attempt to get length of field 'lua_inventory' (a nil value)
stack traceback:
	__FactorioAccess__/control.lua:3607: in function 'open_player_inventory'
	__FactorioAccess__/control.lua:3593: in function <__FactorioAccess__/control.lua:3586>
 402.416 Loading map C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip: 1493022 bytes.
 402.473 Loading level.dat: 988043 bytes.
 402.477 Info Scenario.cpp:178: Map version 2.0.7-0
 402.494 Loading script.dat: 3666 bytes.
 402.505 Checksum for script __level__/control.lua: 3780939624
 402.679 Checksum for script __FactorioAccess__/control.lua: 2676093558
 410.427 Error MainLoop.cpp:1429: Exception at tick 464: The mod Factorio Access Mod (0.15.1) caused a non-recoverable error.
Please report this error to the mod author.

Error while running event FactorioAccess::switch-menu-or-gun (ID 418)
__FactorioAccess__/control.lua:3923: attempt to compare nil with number
stack traceback:
	__FactorioAccess__/control.lua:3923: in function <__FactorioAccess__/control.lua:3785>
 412.251 Loading map C:\projects\in_progress\factorio_access\factorio\saves\_autosave-new.zip: 1493022 bytes.
 412.298 Loading level.dat: 988043 bytes.
 412.302 Info Scenario.cpp:178: Map version 2.0.7-0
 412.321 Loading script.dat: 3666 bytes.
 412.331 Checksum for script __level__/control.lua: 3780939624
 412.508 Checksum for script __FactorioAccess__/control.lua: 2676093558
 419.749 Error MainLoop.cpp:1429: Exception at tick 434: The mod Factorio Access Mod (0.15.1) caused a non-recoverable error.
Please report this error to the mod author.

Error while running event FactorioAccess::switch-menu-or-gun (ID 418)
__FactorioAccess__/control.lua:3923: attempt to compare nil with number
stack traceback:
	__FactorioAccess__/control.lua:3923: in function <__FactorioAccess__/control.lua:3785>
Factorio crashed. Generating symbolized stacktrace, please wait ...
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Util\ReleaseAssert.cpp(7): ReleaseAssertFailed
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaEventDispatcher.cpp(800): LuaEventDispatcher::checkEventsAreAllowed
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaEventDispatcher.cpp(734): LuaEventDispatcher::run
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaEventDispatcher.cpp(565): LuaEventDispatcher::dispatch
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\ScriptTriggerEffectItem.cpp(11): ScriptTriggerEffectItem::applyInternal
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\TriggerEffectItem.cpp(206): TriggerEffectItem::apply
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\TriggerEffect.cpp(45): TriggerEffect::apply
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\TriggerDelivery.cpp(23): TriggerDelivery::apply
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\DirectTriggerItem.cpp(32): DirectTriggerItem::apply
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Trigger\Trigger.cpp(24): Trigger::apply
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\Entity.cpp(456): Entity::postSetup
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\Entity.cpp(352): Entity::runSetup
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Surface\Surface.cpp(296): Surface::setupEntity
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Surface\Surface.cpp(282): Surface::addEntity
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\SpiderEngine.cpp(496): SpiderEngine::validateLegs
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\SpiderEngine.cpp(80): SpiderEngine::setup
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\SpiderVehicle.cpp(160): SpiderVehicle::setup
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Entity\Entity.cpp(345): Entity::runSetup
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Surface\Surface.cpp(296): Surface::setupEntity
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaSurface.cpp(1662): LuaSurface::luaCreateEntity
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaBinder.hpp(281): LuaBinder<LuaGroup>::callWrapperOnObject
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\libraries\Lua\ldo.c(352): luaD_precall
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\libraries\Lua\lvm.c(717): luaV_execute
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\libraries\Lua\lapi.c(1068): f_call
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\libraries\Lua\ldo.c(137): luaD_rawrunprotected
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\libraries\Lua\ldo.c(625): luaD_pcall
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaGameScript.cpp(1877): LuaGameScript::runLuaCommand
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Script\LuaContext.cpp(284): LuaContext::runLuaCommand
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Simulation.cpp(95): Simulation::runCommand
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Gui\SimulationWidget.cpp(48): SimulationWidget::start
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManager.cpp(910): AppManager::loadBackgroundImage
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManager.cpp(588): AppManager::changeStateInternal
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManager.cpp(502): AppManager::popStateToMainMenu
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManager.cpp(344): AppManager::quitGameAndGoToMainMenu
C:\Program Files (x86)\Microsoft Visual Studio\2019\BuildTools\VC\Tools\MSVC\14.29.30133\include\functional(823): std::_Func_impl_no_alloc<`MainLoop::gameUpdateStep'::`75'::<lambda_3>,void>::_Do_call
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManagerStates.cpp(2743): InNoticeBox::process
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\AppManager.cpp(245): AppManager::process
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\MainLoop.cpp(589): MainLoop::prePrepare
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\MainLoop.cpp(682): MainLoop::mainLoopStep
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\MainLoop.cpp(412): MainLoop::run
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Main.cpp(1325): fmain
C:\Users\build\AppData\Local\Temp\factorio-build-uNZvLP\src\Main.cpp(1347): wmain
D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(288): __scrt_common_main_seh
ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FF95A4F7374)
00007FF95A4F7374 (KERNEL32): (filename not available): BaseThreadInitThunk
ERROR: SymGetLineFromAddr64, GetLastError: 487 (Address: 00007FF95A85CC91)
00007FF95A85CC91 (ntdll): (filename not available): RtlUserThreadStart
Stack trace logging done
 541.691 Error LuaEventDispatcher.cpp:800: !map.luaEventsBlocked was not true
 541.691 Error CrashHandler.cpp:643: Received 22
Logger::writeStacktrace skipped.
 541.755 Info CrashHandler.cpp:318: Executable CRC: 3339881057
 541.755 Error Util.cpp:95: Unexpected error occurred. If you're running the latest version of the game you can help us solve the problem by posting the contents of the log file on the Factorio forums.
Please also include the save file(s), any mods you may be using, and any steps you know of to reproduce the crash.
 549.934 Uploading log file
 549.978 Error CrashHandler.cpp:270: Heap validation: success.
 549.978 Creating crash dump.
 550.189 CrashDump success

And dmp attached, in case you don't have one.

Post by **Rseding91** » Tue Oct 22, 2024 10:40 pm

Thanks for the report. You are correct in that the only fix as of now is to not use event triggers for the created effect on entities. The engine is and has been working under the assumption that creating an entity does not invalidate things and lua events happening as a result of creating the entity can't be allowed in all cases.

ahicks · Post by **ahicks** » Tue Oct 22, 2024 11:24 pm

In our use case we are also running a background correction task, because for example newly placed resources on new surfaces don't seem to fire either. That is to say that I would be fine just getting it sometimes, as long as "sometimes" is defined. Also this has had a couple hundred hours of coverage in 1.1 (personally at least 100, and we have other somewhat dedicated testers).

This is the relevant code:

Code: Select all

script.on_event(defines.events.on_script_trigger_effect, function(event)
   if event.effect_id == Consts.NEW_ENTITY_SUBSCRIBER_TRIGGER_ID then
      ScannerEntrypoint.on_new_entity(event.surface_index, event.source_entity)
   end
end)

And:

Code: Select all

-- Called from control.lua whenever control.lua finds out about a new entity.
---@param surface_index number
---@param entity LuaEntity
function mod.on_new_entity(surface_index, entity)
   new_entity_queue:enqueue({ surface_index = surface_index, entity = entity })
end

Then the actual event is handled in on_tick, later. That queue is literally almost verbatim from a Lua programming book.

I could probably be smarter. It is probably possible to wire into new chunk and building events and get something approximating what we need, then let the background reconciliation handle any exception e.g. other mods being sneaky. But being smarter is hard and going to take time, so I'd like to ask before I spend the time on it, whether or not I might see a fix in say the next few months? If the answer is "please go away because 2.0 launched and we have no idea" I understand--I just need to know if being more clever is worth spending the time on my side.

Thanks.

Factorio Forums

[2.0.7] crash in effect triggers (LuaEventDispatcher::checkEventsAreAllowed)

[2.0.7] crash in effect triggers (LuaEventDispatcher::checkEventsAreAllowed)

Re: [2.0.7] crash in effect triggers (LuaEventDispatcher::checkEventsAreAllowed)

Re: [2.0.7] crash in effect triggers (LuaEventDispatcher::checkEventsAreAllowed)