[0.17.65] mod load spike for on_robot_pre_mined on blocked entities

dorfl · Post by **dorfl** » Sun Aug 18, 2019 1:27 am

This might be works-as-expected, but it confused me for a while and I couldn't see it described anywhere, so:

I marked a rail depot for deconstruction before removing a train, so 25 robots went and sat waiting over 25 blocked rail segments -- as expected. But load from mods listening to on_robot_pre_mined jumped by ~0.3ms each on my system, which cumulatively lead to a sustained UPS drop until I removed the train.

Logging from an event handler showed a storm of events for the same few straight-rails:

Code: Select all

{ name = 15, tick = 19507410, robot = { ... }, entity = { name = straight-rail, ... } }

I guess I only noticed this because my base is nearing the 16ms / 60UPS limit on my hardware, but perhaps there is a way to throttle such an event storm? The affected mods were not the usual on-tick type suspects.

FTR, the log from the affected system:

Code: Select all

   0.005 2019-08-18 11:15:38; Factorio 0.17.65 (build 46842, linux64, alpha)
   0.041 Operating system: Linux (Ubuntu 18.04)
   0.041 Program arguments: "/.../factorio/bin/x64/factorio" "-c" "/.../.factorio17/config/config.ini" "--load-game" "bc" 
   0.041 Read data path: /.../factorio/data
   0.041 Write data path: /.../.factorio17 [481020/935683MB]
   0.041 Binaries path: /.../factorio/bin
   0.050 System info: [CPU: AMD Ryzen 5 2600X Six-Core Processor, 12 cores, RAM: 16049 MB]
   0.050 Environment: DISPLAY=:0 WAYLAND_DISPLAY=wayland-0 DESKTOP_SESSION=gnome XDG_SESSION_DESKTOP=gnome XDG_CURRENT_DESKTOP=GNOME __GL_FSAA_MODE=<unset> __GL_LOG_MAX_ANISO=<unset> __GL_SYNC_TO_VBLANK=<unset> __GL_SORT_FBCONFIGS=<unset> __GL_YIELD=<unset>
   0.050 Display options: [FullScreen: 1] [VSync: 0] [UIScale: automatic (100.0%)] [Native DPI: 1] [Screen: 255] [Special: 0000] [Lang: en]
   0.145 Available displays: 1
   0.145  [0]: XWAYLAND0 24" - {[0,0], 1920x1080, SDL_PIXELFORMAT_RGB888, 60Hz}
   0.167 Initialised OpenGL:[0] Radeon RX 580 Series (POLARIS10, DRM 3.27.0, 5.0.0-23-generic, LLVM 8.0.1); driver: 4.5 (Core Profile) Mesa 19.2.0-devel (git-eb862c2 2019-07-15 bionic-oibaf-ppa)
   0.167   [Extensions] s3tc:yes; KHR_debug:yes; ARB_clear_texture:yes, ARB_copy_image:yes
   0.167   [Version] 4.5
   0.167 Graphics settings preset: very-high
   0.167   Dedicated video memory size 8192 MB
   0.176 Graphics options: [Graphics quality: high] [Video memory usage: all] [Light scale: 50%] [DXT: high-quality]
   0.176                   [Max load threads: 32] [Max texture size: 0] [Tex.Stream.: 0] [Rotation quality: normal] [Color: 32bit]
   0.440 Loading mod settings ModuleInserter 4.1.6 (settings.lua)
   0.440 Loading mod settings railloader 0.6.1 (settings.lua)
   0.440 Loading mod settings angelsaddons-oresilos 0.5.1 (settings.lua)
   0.440 Loading mod settings bulkteleport 0.1.26 (settings.lua)
   0.440 Loading mod settings even-distribution 0.3.10 (settings.lua)
   0.440 Loading mod settings Flare Stack 2.2.3 (settings.lua)
   0.440 Loading mod settings laserlines 0.1.6 (settings.lua)
   0.441 Loading mod settings miniloader 1.8.2 (settings.lua)
   0.441 Loading mod settings qol_research 2.3.1 (settings.lua)
   0.443 Loading mod settings robosubstation 0.1.6 (settings.lua)
   0.443 Loading mod settings SpaceMod 0.4.4 (settings.lua)
   0.443 Loading mod settings TinyStart 0.17.3 (settings.lua)
   0.443 Loading mod settings VehicleGrid 1.1.2 (settings.lua)
   0.444 Loading mod settings VehicleSnap 1.17.3 (settings.lua)
   0.446 Loading mod core 0.0.0 (data.lua)
   0.539 Loading mod base 0.17.65 (data.lua)
   0.734 Loading mod ModuleInserter 4.1.6 (data.lua)
   0.835 Loading mod railloader 0.6.1 (data.lua)
   0.940 Loading mod aai-vehicles-chaingunner 0.4.1 (data.lua)
   1.039 Loading mod aai-vehicles-hauler 0.4.2 (data.lua)
   1.139 Loading mod aai-vehicles-warden 0.3.2 (data.lua)
   1.239 Loading mod angelsaddons-oresilos 0.5.1 (data.lua)
   1.338 Loading mod bitercide 0.1.4 (data.lua)
   1.437 Loading mod Blueprint_Flip_Turn_017 1.0.0 (data.lua)
   1.539 Loading mod bulkteleport 0.1.26 (data.lua)
   1.641 Loading mod bullet-trails 0.4.1 (data.lua)
   1.741 Loading mod Combat_by_Samuel 1.1.1 (data.lua)
   1.845 Loading mod dorfl1 0.1.8 (data.lua)
   1.947 Loading mod even-distribution 0.3.10 (data.lua)
   2.048 Loading mod Flare Stack 2.2.3 (data.lua)
   2.150 Loading mod Flow Control 3.0.4 (data.lua)
   2.256 Loading mod FNEI 0.2.7 (data.lua)
   2.362 Loading mod laserlines 0.1.6 (data.lua)
   2.463 Loading mod markers 0.1.2 (data.lua)
   2.561 Loading mod miniloader 1.8.2 (data.lua)
   2.667 Loading mod OmegaDrill 0.1.9 (data.lua)
   2.774 Loading mod Portable_power 0.17.2 (data.lua)
   2.878 Loading mod qol_research 2.3.1 (data.lua)
   2.990 Loading mod Roboport Recharge Upgrade 1.7.0 (data.lua)
   3.097 Loading mod robosubstation 0.1.6 (data.lua)
   3.203 Loading mod Robot_Battery_Research 0.1.2 (data.lua)
   3.308 Loading mod shortwave 0.1.7 (data.lua)
   3.413 Loading mod smr 0.1.2 (data.lua)
   3.517 Loading mod SpaceMod 0.4.4 (data.lua)
   3.622 Loading mod stdlib 1.2.2 (data.lua)
   3.724 Loading mod TinyStart 0.17.3 (data.lua)
   3.829 Loading mod VehicleGrid 1.1.2 (data.lua)
   3.936 Loading mod VehicleSnap 1.17.3 (data.lua)
   4.043 Loading mod autodrive 0.1.13 (data.lua)
   4.155 Loading mod base 0.17.65 (data-updates.lua)
   4.252 Loading mod aai-vehicles-chaingunner 0.4.1 (data-updates.lua)
   4.354 Loading mod aai-vehicles-hauler 0.4.2 (data-updates.lua)
   4.456 Loading mod aai-vehicles-warden 0.3.2 (data-updates.lua)
   4.559 Loading mod angelsaddons-oresilos 0.5.1 (data-updates.lua)
   4.661 Loading mod bullet-trails 0.4.1 (data-updates.lua)
   4.763 Loading mod dorfl1 0.1.8 (data-updates.lua)
   4.866 Loading mod miniloader 1.8.2 (data-updates.lua)
   4.969 Loading mod robosubstation 0.1.6 (data-updates.lua)
   5.071 Loading mod Squeak Through 1.3.0 (data-updates.lua)
   5.174 Loading mod VehicleGrid 1.1.2 (data-updates.lua)
   5.278 Loading mod autodrive 0.1.13 (data-updates.lua)
   5.392 Loading mod aai-vehicles-warden 0.3.2 (data-final-fixes.lua)
   5.493 Loading mod even-distribution 0.3.10 (data-final-fixes.lua)
   5.601 Loading mod Flare Stack 2.2.3 (data-final-fixes.lua)
   5.713 Loading mod robosubstation 0.1.6 (data-final-fixes.lua)
   5.825 Loading mod SpaceMod 0.4.4 (data-final-fixes.lua)
   5.937 Loading mod autodrive 0.1.13 (data-final-fixes.lua)
   6.059 Checksum for core: 2403267992
   6.059 Checksum of base: 3948013453
   6.059 Checksum of ModuleInserter: 1378542484
   6.059 Checksum of railloader: 2268167061
   6.059 Checksum of aai-vehicles-chaingunner: 1784905760
   6.059 Checksum of aai-vehicles-hauler: 3776294681
   6.059 Checksum of aai-vehicles-warden: 3121478813
   6.059 Checksum of angelsaddons-oresilos: 1545536894
   6.059 Checksum of bitercide: 2636844420
   6.059 Checksum of Blueprint_Flip_Turn_017: 3610832871
   6.059 Checksum of bulkteleport: 4131271920
   6.059 Checksum of bullet-trails: 3671570151
   6.059 Checksum of Combat_by_Samuel: 3034607917
   6.059 Checksum of dorfl1: 2275006209
   6.059 Checksum of even-distribution: 531838026
   6.059 Checksum of Flare Stack: 2374449
   6.059 Checksum of Flow Control: 3821924777
   6.059 Checksum of FNEI: 947672031
   6.059 Checksum of laserlines: 172064009
   6.059 Checksum of markers: 1521552860
   6.059 Checksum of miniloader: 1200297475
   6.059 Checksum of OmegaDrill: 4283505955
   6.059 Checksum of Portable_power: 2555548879
   6.059 Checksum of qol_research: 3650033342
   6.059 Checksum of Roboport Recharge Upgrade: 987859923
   6.059 Checksum of robosubstation: 27657128
   6.059 Checksum of Robot_Battery_Research: 3384545753
   6.059 Checksum of shortwave: 588468429
   6.059 Checksum of smr: 3758407569
   6.059 Checksum of SpaceMod: 3787441445
   6.059 Checksum of Squeak Through: 3677677690
   6.059 Checksum of stdlib: 68667574
   6.059 Checksum of TinyStart: 2411895616
   6.059 Checksum of VehicleGrid: 4059842795
   6.059 Checksum of VehicleSnap: 3082759310
   6.059 Checksum of autodrive: 2286736179
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-send1.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-recv1.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-send2.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-recv2.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-send3.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-recv3.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-send4.energy_source
   6.142 Warning EnergySourcePrototype.cpp:85: emissions_per_second_per_watt used, use emissions_per_minute: ROOT.furnace.bulkteleport-energizer-recv4.energy_source
   6.142 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 0.008): ROOT.furnace.flare-stack.energy_source
   6.142 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 5e-05): ROOT.furnace.incinerator.energy_source
   6.142 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 5e-05): ROOT.furnace.electric-incinerator.energy_source
   6.142 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 0.008): ROOT.furnace.vent-stack.energy_source
   6.155 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 1e-04): ROOT.mining-drill.omega-drill.energy_source
   6.261 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 1e-05): ROOT.generator-equipment.portable-generator-equipment.burner
   6.261 Warning EnergySourcePrototype.cpp:91: emissions used, use emissions_per_minute (proposed value 1e-05): ROOT.generator-equipment.portable-reactor-equipment.burner
   6.305 Loading sounds...
   6.325 Info PlayerData.cpp:68: Local player-data.json available, timestamp 1566090143
   6.325 Info PlayerData.cpp:75: Cloud player-data.json unavailable
   6.470 Initial atlas bitmap size is 16384
   6.494 Created atlas bitmap 16384x16376 [none]
   6.537 Created atlas bitmap 16384x16376 [none]
   6.537 Created atlas bitmap 16384x456 [none]
   6.537 Created atlas bitmap 8192x3872 [decal]
   6.538 Created atlas bitmap 16384x4352 [low-object, linear-minification]
   6.539 Created atlas bitmap 8192x3744 [mipmap, linear-minification, linear-magnification, linear-mip-level]
   6.540 Created atlas bitmap 16384x6880 [terrain, mipmap, linear-minification, linear-mip-level]
   6.540 Created atlas bitmap 4096x1600 [smoke, mipmap, linear-minification, linear-magnification]
   6.540 Created atlas bitmap 480x160 [low-object, mipmap, linear-minification, linear-magnification, linear-mip-level]
   6.540 Created atlas bitmap 4096x2304 [icon, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level]
   6.540 Created atlas bitmap 2048x256 [icon-background, not-compressed, mipmap, linear-minification, linear-magnification, linear-mip-level, ]
   6.541 Created atlas bitmap 8192x1496 [alpha-mask]
   6.543 Created atlas bitmap 16384x13944 [shadow, linear-magnification, alpha-mask]
   6.543 Created atlas bitmap 8192x2352 [shadow, mipmap, linear-magnification, alpha-mask]
   6.549 Texture processor created (2048). GPU accelerated compression Supported: yes, Enabled: yes/yes. Test passed. YCoCgDXT PSNR: 35.83, BC3 PSNR: 33.82
   6.976 Parallel Sprite Loader initialized (threads: 11)
  15.295 Sprites loaded
  15.308 Generated mipmaps (4) for atlas [4] of size 16384x4352   
  15.312 Generated mipmaps (3) for atlas [5] of size 8192x3744   
  15.324 Generated mipmaps (3) for atlas [6] of size 16384x6880   
  15.326 Generated mipmaps (3) for atlas [7] of size 4096x1600   
  15.327 Generated mipmaps (4) for atlas [8] of size 480x160   
  15.328 Generated mipmaps (5) for atlas [9] of size 4096x2304   
  15.329 Generated mipmaps (3) for atlas [13] of size 8192x2352   
  15.330 Custom mipmaps uploaded.
  15.379 Custom inputs active: 6
  15.485 Factorio initialised
  15.486 Warning FileUtil.cpp:527: bc not found; using /.../.factorio17/saves/bc.zip
  15.486 Loading map /.../.factorio17/saves/bc.zip: 15316123 bytes.
  15.504 Loading level.dat: 44018630 bytes.
  15.512 Info Scenario.cpp:187: Map version 0.17.65-2
  16.796 Loading script.dat: 110706 bytes.
  16.798 Checksum for script /.../.factorio17/temp/currently-playing/control.lua: 72150939
  16.801 Checksum for script __ModuleInserter__/control.lua: 1975220697
  16.804 Checksum for script __railloader__/control.lua: 77193887
  16.806 Checksum for script __aai-vehicles-warden__/control.lua: 1482635462
  16.806 Checksum for script __bitercide__/control.lua: 557089162
  16.807 Checksum for script __Blueprint_Flip_Turn_017__/control.lua: 3983432184
  16.808 Checksum for script __bulkteleport__/control.lua: 2505300625
  16.809 Script @__even-distribution__/framework.lua:72: 0 [ED] Initializing framework... DEBUG = false
  16.809 Script @__even-distribution__/framework.lua:72: 0 [ED] Registering custom scripts...
  16.809 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: metatables
  16.810 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: util
  16.810 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: helpers
  16.810 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: setup
  16.810 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: visuals
  16.811 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: drag
  16.811 Script @__even-distribution__/framework.lua:72: 0 [ED] Script: cleanup
  16.811 Script @__even-distribution__/framework.lua:72: 0 [ED] Registering default event handlers...
  16.811 Script @__even-distribution__/framework.lua:72: 0 [ED] Registering custom inputs...
  16.811 Script @__even-distribution__/framework.lua:72: 0 [ED] Input: inventory-cleanup   event: on_inventory_cleanup
  16.812 Script @__even-distribution__/framework.lua:72: 0 [ED] Successfully initialized
  16.812 Checksum for script __even-distribution__/control.lua: 3626673393
  16.812 Checksum for script __Flow Control__/control.lua: 894715649
  16.821 Checksum for script __FNEI__/control.lua: 3215094452
  16.822 Checksum for script __laserlines__/control.lua: 3427091822
  16.823 Checksum for script __markers__/control.lua: 277108317
  16.826 Checksum for script __miniloader__/control.lua: 2775463527
  16.829 Checksum for script __qol_research__/control.lua: 3945794928
  16.829 Checksum for script __robosubstation__/control.lua: 3629559567
  16.830 Checksum for script __shortwave__/control.lua: 1828527205
  16.831 Checksum for script __smr__/control.lua: 1314055490
  16.833 Checksum for script __SpaceMod__/control.lua: 718259292
  16.834 Checksum for script __TinyStart__/control.lua: 4198332849
  16.835 Checksum for script __VehicleSnap__/control.lua: 1248096782
  16.836 Checksum for script __autodrive__/control.lua: 3849002776
  16.842 Applying migration: Bulk Teleporters: 0.1.26-techs-recipes.lua
  16.867 Applying migration: Autodrive: 0.1.13-techs-recipes.lua

dorfl · Post by **dorfl** » Sun Aug 18, 2019 1:39 am

Will try to get the obligatory screenshots from another box. For some reason screen capture is showing up all black on Wayland...

Post by **Rseding91** » Sun Aug 18, 2019 4:27 am

Thanks for the report however that's normal behavior. The event is fired each tick as the robot tires to perform its job: the pre-event fires, it tries, and if it fails it ends the logic update for the robot. If it succeeds it fires the standard event and goes about its business.

Lua events are not free. You're seeing the direct ramification of frequent events and one of the main reasons we don't have events for super common things.

Factorio Forums

[0.17.65] mod load spike for on_robot_pre_mined on blocked entities

[0.17.65] mod load spike for on_robot_pre_mined on blocked entities

Re: [0.17.65] mod load spike for on_robot_pre_mined on blocked entities

Re: [0.17.65] mod load spike for on_robot_pre_mined on blocked entities