[16.36] Huge lag with inventory manipulating script and personal roboport

[Gergely]

This bug is very specific and consistent. The game starts to lag a LOT (everything slows down) if I equip modular armor with a Personal Roboport. As soon as I take it out, the lagging stops.

It does not happen with the non portable version of the roboport. (AKA: The ENTITY roboport.)
The scenario I used is linked in my signature.

https://www.youtube.com/watch?v=fj2MG8Qtf-E

Code: Select all

   0.002 2018-04-17 19:58:01; Factorio 0.16.36 (build 36253, win64, steam)
   0.002 Operating system: Windows 10 (version 1709) 
   0.002 Program arguments: "C:\Program Files (x86)\Steam\steamapps\common\Factorio\bin\x64\Factorio.exe" "--window-size" "maximized" 
   0.002 Read data path: C:/Program Files (x86)/Steam/steamapps/common/Factorio/data
   0.002 Write data path: C:/Users/balintgergely/AppData/Roaming/Factorio [86820/121552MB]
   0.002 Binaries path: C:/Program Files (x86)/Steam/steamapps/common/Factorio/bin
   0.013 System info: [CPU: Intel(R) Core(TM) i7-7700HQ CPU @ 2.80GHz, 8 cores, RAM: 3192/7804 MB, page: 3637/9724 MB, virtual: 228/134217727 MB, extended virtual: 0 MB]
   0.016 Display options: [FullScreen: 0] [VSync: 0] [UIScale: system (100.0%)] [MultiSampling: OFF] [Screen: 255] [Lang: en]
   0.017 Available display adapters: 1
   0.017  [0]: \\.\DISPLAY1 - Intel(R) HD Graphics 630 {0x05, [0,0], 1920x1080, 32bit, 60Hz}
   0.018 Create display on adapter 0. Size 1280x720 at position [310, 162].
   1.013 Initialised Direct3D:[0] NVIDIA GeForce GTX 1050 Ti; driver: nvldumdx.dll 23.21.13.9065
   1.022   Video memory size (dedicated video/dedicated system/shared system/available): 4021/0/3902/4092 MB
   1.078 DSound: Starting _dsound_update thread
   1.078 DSound: Enter _dsound_update; tid=12252
   1.079 Device reset internal.
   1.082 Desktop composition is active.
   1.082 Graphics settings preset: high
   1.083 Graphics options: [Graphics quality: high] [Video memory usage: all] [Light scale: 100%] [DXT: false] [Shader: 1]
   1.083                   [Parallel sprite loading: 1] [Max texture size: 0/8192] [Bmp cache: 0] [Sprite slicing: 1] [Low quality rotation: 0]
   1.162 Error GlobalModSettings.cpp:107: Failed to migrate mod settings file: Error when opening C:\Users\balintgergely\AppData\Roaming\Factorio\mods\mod-settings.json for reading: No such file or directory
   1.164 Loading mod core 0.0.0 (data.lua)
   1.189 Loading mod base 0.16.36 (data.lua)
   1.367 Loading mod base 0.16.36 (data-updates.lua)
   1.423 Checksum for core: 1316978547
   1.423 Checksum of base: 4140083139
   1.423 Checksum of creative-scenario: 0
   1.423 Checksum of factory-floor: 0
   1.423 Checksum of io-production-challenge: 0
   1.553 Loading sounds...
   1.774 Info PlayerData.cpp:67: Local player-data.json unavailable
   1.774 Info PlayerData.cpp:70: Cloud player-data.json available, timestamp 1522607754
   1.935 Loaded shader file C:/Program Files (x86)/Steam/steamapps/common/Factorio/data/core/graphics/shaders/game.cso
   1.935 Loaded shader file C:/Program Files (x86)/Steam/steamapps/common/Factorio/data/core/graphics/shaders/zoom-to-world.cso
   1.936 Loaded shader file C:/Program Files (x86)/Steam/steamapps/common/Factorio/data/core/graphics/shaders/alpha-mask.cso
   1.968 Initial atlas bitmap size is 16384
   2.023 Created atlas bitmap 16384x16383 [none]
   2.600 Created atlas bitmap 16384x4290 [none]
   2.738 Created atlas bitmap 16384x6916 [shadow]
   2.962 Created atlas bitmap 16384x2104 [decal]
   3.030 Created atlas bitmap 8192x5572 [mipmap]
   3.117 Created atlas bitmap 8192x800 [mipmap, smoke]
   3.133 Created atlas bitmap 8192x8172 [linear-minification, mipmap, terrain]
   3.263 Created atlas bitmap 8192x1360 [linear-minification, mipmap, terrain]
   3.283 Created atlas bitmap 8192x2092 [no-crop, trilinear-filtering, icon, light]
   3.317 Created atlas bitmap 8192x924 [alpha-mask]
  26.284 Sprites loaded
  26.284 Convert atlas 8192x5572 to: mipmap 
  26.519 Convert atlas 8192x800 to: mipmap 
  26.551 Convert atlas 8192x8172 to: min-linear 
  26.884 Convert atlas 8192x1360 to: min-linear 
  26.940 Convert atlas 8192x2092 to: trilinear-filtering 
  27.023 Convert atlas 8192x924 to: alpha-mask
  27.898 Custom inputs active: 0
  27.941 Factorio initialised
  46.641 Loading Level.dat: 1017249 bytes.
  46.642 Info Scenario.cpp:136: Map version 0.16.36-2
  46.681 Checksum for script C:/Users/balintgergely/AppData/Roaming/Factorio/temp/currently-playing/control.lua: 2691789386
 180.890 DSound: Stopping voice
 180.890 DSound: Joining thread
 180.893 DSound: Exit _dsound_update; tid=12252
 180.893 DSound: Waiting for voice to stop ... signaled
 180.894 DSound: Joined thread
 180.894 DSound: Destroying thread
 180.894 DSound: Thread destroyed
 180.894 DSound: Releasing buffer
 180.894 DSound: Voice stopped
 180.894 DSound: Deallocating voice
 180.894 DSound: Deallocated voice
 180.922 Steam API shutdown.
 180.969 Goodbye

This time, it is a new laptop.

Edit: The problem is unearthed by my scenario script, because the lag only happens when I turn on auto fill inventory. However, my script does not interact with the modular armor in any way other than refilling it's durability. (Switching that functionality off however, does not solve the problem!) This might be some "noisy" code "listening" to changes that is "registered" when the player has equipment that is affected by the inventory, and since my script updates every single slot in the inventory, the game notifies the personal roboport 30+[inventory slot bonus]+[# of item prototypes] times each tick. Which is obviously very bad for the game's health... Something nasty is up with set_stack().

I think I did use the personal roboport with my scenario in 0.16 without this issue appearing. I was trying to go back to... say 0.16.15 to confirm that but I could not find the download.

[orzelek]

Can you add screenshot with timings from F4/F5 debug menus?
Might show if it's a script time in the scenario or game doing something.

You can also use log() in script around suspect areas and check timestamps in log to figure out if there is something specific in your code that causes the delay. You get about 1ms accuracy so if fishy stuff is going on it might be visible.

[Rseding91]

Thanks for the report however nothing you showed is bugged. You're changing the character inventory several hundred times per game tick which has an overhead.

Simply don't do that. Only change a slot when it needs to be changed - don't "set_stack" unless it's not what you want it to be.

[Gergely]

Sorry... I am waaaay used to listener hooks that notify their peers only if a change has occurred instead of on every write operation.

Will do what you said...

And the next time I ever see something like that, I run it through freeplay as well...
Would you mind updating the documentation for set_stack in order to avoid this issue in the future?

[darkfrei]

You're changing the character inventory several hundred times per game tick which has an overhead.

Is it possible to change all inventory slots with only one operation? For example something like

Code: Select all

main_inventory.set_stacks({stack_list})

[Rseding91]

The way set_stack works is it first clears the current stack then sets the new item.

So you get 2 change notifications every time you do set_stack.