minetest-mods / unified_inventory

An extensible inventory mod which allows searching crafting and browsing for recipes in the same dialogue.
Other
49 stars 38 forks source link

Slow to start server, gets slower the more nodes it has to index. 9+ minutes added to my server start. #198

Closed mrbid closed 2 years ago

mrbid commented 2 years ago

Surly whatever unified inventory is generating for each node can be cached on file so that it does not have to re-compute the whole thing on each server reboot? Waiting 5-10 minutes per server restart is a bit long. I do have more nodes in creative than most servers but still.

SmallJoker commented 2 years ago

Are you sure this is related to unified inventory? Please enable the mod profiler (profiler.load = true) and generate a report in-game (command /profiler save). You can also get startup time reports with --verbose (or verbose logging level).

What's your server specifications? I cannot reproduce this on my desktop.

mrbid commented 2 years ago

Are you sure this is related to unified inventory? Please enable the mod profiler (profiler.load = true) and generate a report in-game (command /profiler save). You can also get startup time reports with --verbose (or verbose logging level).

What's your server specifications? I cannot reproduce this on my desktop.

Profiler snippet:

 unified_inventory:                              |           1 | 618696 |     1628 |    0.0 |  94.3 |   1.4
  - on_player_receive_fields[1] ............. |         19 |         19 |         19 |    0.4 |    0.4 |   0.4
  - on_joinplayer[2] ..................................  |          7 |           7 |           7 |    0.0 |    0.0 |   0.0
  - on_player_receive_fields[2] .............. |          2 |           2 |           2 |    0.0 |    0.0 |   0.0
  - on_joinplayer[1] ..................................  | 618688 | 618688 | 618688 |  94.3 |  94.3 |   94.3
  - globalstep[1] ........................................  |         1 |        116 |         12 |    0.0 |   11.5 |   1.1

Seems Unified Inventory spends most of its time in on_joinplayer().

2022-02-10 13:35:08: INFO[Server]: Server: Maximum lag peaked to 2.5 s
Unified Inventory. inventory size: 55519
2022-02-10 13:35:37: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:36:07: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:36:37: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:37:07: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:37:37: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:38:07: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:38:37: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:39:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:39:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:40:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:40:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:41:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:41:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:42:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:42:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:43:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:43:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:44:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:44:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:45:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:45:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:46:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:46:38: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:47:08: INFO[Main]: Client packetcounter (30s): sum=0 avg=0/s
2022-02-10 13:47:22: INFO[Server]: [Tubelib] Data maintenance started

Otherwise all I can tell you, after executing with profiler.load = true and --verbose is that Unified Inventory loads at 13:35:08 and ends at 13:47:22 ~12 minutes later.

If I delete Unified Inventory then this 12 minute delay in server restart is solved, although this would not be the satisfactory solution.

I would be willing to compromise and remove the offending code causing the delay on just my servers, if it was reasonable to drop the functionality that is causing this problem, I see that there are three register_on_joinplayer() functions. I don't want to just start hacking away at a code base I have no experience in and fall into short sighted pitfalls later on down the road so I will await to be advised before taking this option as a last measure.

SmallJoker commented 2 years ago

There's no data loss if you modify unified_inventory a bit. on_joinplayer only calls to two relevant functions: https://github.com/minetest-mods/unified_inventory/blob/25c40fea6cb9c1d563137d3d9088982b073a4435/internal.lua#L315-L316 and indirectly https://github.com/minetest-mods/unified_inventory/blob/25c40fea6cb9c1d563137d3d9088982b073a4435/internal.lua#L255-L256

Which mod do I need to get this many item registrations (55k) ? I suppose there is something wrong with the filter function, but I cannot narrow this down yet. I'd recommend you to comment sections in those functions to get a rough idea where the problem lies. Simple print("A,b,c....") statements should be precise enough due to this enormous long startup.

mrbid commented 2 years ago

Well essentially I have removed not_in_creative_inventory in primarily; moreblocks, xdecor, and homedecor_modpack.

But the best example if you want to completely copy my server worldmods is to clone; https://github.com/mrbid/Minetest-Worldmods/

You'll just want to remove the irc and irc_commands folders from /system_mods to avoid configuring trusted mods.

Thank you for the direction I will begin experimenting with the two functions and see if I can find an adequate solution. Well I am stumped as it seems the profiler does not catch what is causing this delay, I commented out all the code for every on_joinplayer, apply_filter, and get_formspec and still no improvement on that load speed.

mrbid commented 2 years ago

You can merge https://github.com/minetest-mods/unified_inventory/pull/199 and close this issue.

SmallJoker commented 2 years ago

199 merged.