What the... server not loading mods after mod update

[MrPhil]

I have a script that I run from time to time to update the mods on my private server and after the latest time running it I get the following in the log and the server won't start:

2024-09-27 18:00:28: [Main]: Using game specified by --gameid on the command line
2024-09-27 18:00:28: WARNING[Main]: /!\ You are using the old mod storage files backend. This backend is deprecated and may be removed in a future release /!\
2024-09-27 18:00:28: WARNING[Main]: Switching to SQLite3 is advised, please read http://wiki.minetest.net/Database_backends.
2024-09-27 18:00:28: WARNING[Main]: Mod name conflict detected: "farming"
2024-09-27 18:00:28: WARNING[Main]: Will not load: /usr/local/share/minetest/games/minetest_game/mods/farming
2024-09-27 18:00:28: WARNING[Main]: Overridden by: /var/games/minetest-server/.minetest/mods/farming
2024-09-27 18:00:28: WARNING[Main]: Mod name conflict detected: "fire"
2024-09-27 18:00:28: WARNING[Main]: Will not load: /usr/local/share/minetest/games/minetest_game/mods/fire
2024-09-27 18:00:28: WARNING[Main]: Overridden by: /var/games/minetest-server/.minetest/mods/fire
2024-09-27 18:00:28: WARNING[Main]: Mod name conflict detected: "serialize_lib"
2024-09-27 18:00:28: WARNING[Main]: Will not load: /var/games/minetest-server/.minetest/mods/advtrains/serialize_lib
2024-09-27 18:00:28: WARNING[Main]: Overridden by: /var/games/minetest-server/.minetest/mods/serialize_lib
2024-09-27 18:00:28: ERROR[Main]: The following mods could not be found: "homedecor_modpack"
2024-09-27 18:00:28: ACTION[Main]: Server: Shutting down
2024-09-27 18:00:29: ERROR[Main]: ServerError: Some mods have unsatisfied dependencies:
2024-09-27 18:00:29: ERROR[Main]: - armor_nether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - climate_api is missing: lighting_monoid
2024-09-27 18:00:29: ERROR[Main]: - regional_weather is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - livingnether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - mobs_balrog is missing: armor_nether nether
2024-09-27 18:00:29: ERROR[Main]: - nether is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - sailing_kit is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: Install and enable the required mods, or disable the mods causing errors.
2024-09-27 18:00:29: ERROR[Main]: Note: this may be caused by a dependency cycle, in which case try updating the mods.

The mods that are supposedly missing are there and enabled in world.mt. File access rights/owner for the mod directories are correct. What am I missing?



Interesting, running with 'info' level debugging yields the following, like it has no idea where the mods are, other than the ones included in minetest_game:

root@racknerd-xxxxxx:/var/games/minetest-server/.minetest/mods# minetestserver --info --config /etc/minetest/minetest.conf --logfile /var/log/minetest/minetest.log --gameid minetest
2024-09-27 17:57:48: INFO[Main]: Using system-wide paths (NOT RUN_IN_PLACE)
2024-09-27 17:57:48: INFO[Main]: Detected share path: /usr/local/share/minetest
2024-09-27 17:57:48: INFO[Main]: Detected user path: /root/.minetest
2024-09-27 17:57:48: INFO[Main]: Detected cache path: /root/.cache/minetest
2024-09-27 17:57:48: INFO[Main]: Using in-place locale directory /usr/local/share/minetest/locale even though a static one was provided.
2024-09-27 17:57:48: INFO[Main]: Minetest 5.9.1 (Linux)
2024-09-27 17:57:48: INFO[Main]: Using LuaJIT 2.1.1699801871
2024-09-27 17:57:48: INFO[Main]: Built by GCC 8.3
2024-09-27 17:57:48: INFO[Main]: Running on Linux/4.19.0 x86_64
2024-09-27 17:57:48: INFO[Main]: BUILD_TYPE=Release
2024-09-27 17:57:48: INFO[Main]: RUN_IN_PLACE=0
2024-09-27 17:57:48: INFO[Main]: USE_CURL=1
2024-09-27 17:57:48: INFO[Main]: STATIC_SHAREDIR="/usr/local/share/minetest"
2024-09-27 17:57:48: INFO[Main]: STATIC_LOCALEDIR="/usr/local/share/locale"
2024-09-27 17:57:48: INFO[Main]: SER_FMT_VER_HIGHEST_READ=29 LATEST_PROTOCOL_VERSION=45
2024-09-27 17:57:48: INFO[Main]: Gettext: domainname="minetest" path="/usr/local/share/minetest/locale"
2024-09-27 17:57:48: INFO[Main]: Message locale is now set to: LC_CTYPE=en_US.UTF-8;LC_NUMERIC=C;LC_TIME=en_US.UTF-8;LC_COLLATE=en_US.UTF-8;LC_MONETARY=en_US.UTF-8;LC_MESSAGES=en_US.UTF-8;LC_PAPER=en_US.UTF-8;LC_NAME=en_US.UTF-8;LC_ADDRESS=en_US.UTF-8;LC_TELEPHONE=en_US.UTF-8;LC_MEASUREME
2024-09-27 17:57:48: INFO[Main]: NT=en_US.UTF-8;LC_IDENTIFICATION=en_US.UTF-8
2024-09-27 17:57:48: [Main]: Using game specified by --gameid on the command line
2024-09-27 17:57:48: INFO[Main]: Server created for gameid "minetest"
2024-09-27 17:57:48: INFO[Main]: - world: /var/games/minetest-server/.minetest/worlds/world2/
2024-09-27 17:57:48: INFO[Main]: - game: /usr/local/share/minetest/games/minetest_game
2024-09-27 17:57:48: INFO[Main]: Initializing world at /var/games/minetest-server/.minetest/worlds/world2/
2024-09-27 17:57:48: INFO[Main]: ObjDefManager: added biome: name="default" index=0 uid=62
2024-09-27 17:57:48: INFO[Main]: EmergeManager: using 1 threads
2024-09-27 17:57:48: INFO[Main]: BanManager: loading from /var/games/minetest-server/.minetest/worlds/world2//ipban.txt
2024-09-27 17:57:48: WARNING[Main]: /!\ You are using the old mod storage files backend. This backend is deprecated and may be removed in a future release /!\
2024-09-27 17:57:48: WARNING[Main]: Switching to SQLite3 is advised, please read http://wiki.minetest.net/Database_backends.
2024-09-27 17:57:48: ERROR[Main]: The following mods could not be found: "xcompat" "schemedit" "nether" "morelights" "mymillwork" "animalia" "commoditymarket" "mail" "bakedclay" "fmod" "font_api" "clementinetree" "signs_api" "markers" "creatura" "armor_crystal" "armor_gold" "armor_mithril"
2024-09-27 17:57:48: ERROR[Main]: "homedecor_fences" "mobkit" "lightning" "advtrains_signals_ks" "moreblocks" "unified_inventory_plus" "home_workshop_machines" "home_workshop_misc" "homedecor_misc" "mesecons_gates" "armor_wood" "mesecons_delayer" "mesecons" "3d_armor_ui" "technic_chests"
2024-09-27 17:57:48: ERROR[Main]: "oak" "homedecor_bedroom" "wieldview" "mobs_bat" "mesecons_random" "mobs_mc" "baldcypress" "homedecor_3d_extras" "advtrains" "pomegranate" "armor_nether" "boards" "mesecons_materials" "lemontree" "moreores" "armor_diamond" "mesecons_torch" "mesecons_wires"
2024-09-27 17:57:48: ERROR[Main]: "homedecor_seating" "drawers" "homedecor_doors_and_gates" "homedecor_trash_cans" "bonemeal" "signs" "banisters" "advtrains_luaautomation" "mobs_animal" "livingnether" "homedecor_electronics" "hudbars" "homedecor_clocks" "facade" "protector" "willow" "hand
2024-09-27 17:57:48: ERROR[Main]: le_schematics" "unifieddyes" "digilines" "hopper" "home_vending_machines" "pineapple" "chestnuttree" "ontime_clocks" "atm" "homedecor_furniture" "mesecons_button" "larch" "player_monoids" "sailing_kit" "homedecor_pictures_and_paintings" "mesecons_lightston
2024-09-27 17:57:48: ERROR[Main]: e" "3d_armor" "mesecons_solarpanel" "homedecor_books" "homedecor_lighting" "mesecons_insulated" "mesecons_alias" "climate_api" "birch" "homedecor_climate_control" "unified_inventory" "mobs_birds" "places" "mahogany" "bows" "advtrains_train_japan" "mesecons
2024-09-27 17:57:48: ERROR[Main]: _stickyblocks" "technic" "mesecons_receiver" "morelights_extras" "ambience" "basic_machines" "fakelib" "mesecons_detector" "homedecor_electrical" "maple" "homedecor_laundry" "ebony" "plumtree" "worldedit_brush" "homedecor_exterior" "homedecor_furniture_med
2024-09-27 17:57:48: ERROR[Main]: ieval" "mobs_balrog" "homedecor_gastronomy" "city_commoditymarket" "mesecons_luacontroller" "morelights_vintage" "worldedit_gui" "sound_api_core" "cottages" "homedecor_tables" "hollytree" "fachwerk" "advtrains_line_automation" "flowerpot" "mesecons_hydrotu
2024-09-27 17:57:48: ERROR[Main]: rbine" "mobs" "homedecor_windows_and_treatments" "itemframes" "palm" "futil" "mesecons_pressureplates" "homedecor_common" "bamboo" "technic_worldgen" "mesecons_walllever" "shields" "cherrytree" "mesecons_mvps" "mesecons_powerplant" "font_metro" "jacaranda"
2024-09-27 17:57:48: ERROR[Main]: "mesecons_microcontroller" "mesecons_noteblock" "lrfurn" "teleport_potion" "ethereal" "fake_fire" "mesecons_pistons" "advtrains_itrainmap" "mesecons_blinkyplant" "elevator" "homedecor_office" "mesecons_switch" "hades_sounds_atmos" "hbhunger" "smartrenting
2024-09-27 17:57:48: ERROR[Main]: " "advtrains_assets" "mg_villages" "currency" "fishing" "lavalamp" "mesecons_fpga" "advtrains_interlocking" "3d_armor_stand" "regional_weather" "technic_cnc" "advtrains_train_steam" "mesecons_doors" "pipeworks" "signs_road" "mobs_monster" "mesecons_movesto
2024-09-27 17:57:48: ERROR[Main]: nes" "display_api" "worldedit_commands" "homedecor_roofing" "building_blocks" "areas" "3d_armor_sfinv" "advtrains_train_subway" "morelights_modern" "serialize_lib" "digtron" "homedecor_foyer" "advtrains_train_track" "homedecor_bathroom" "mesecons_lamp" "ho
2024-09-27 17:57:48: ERROR[Main]: medecor_wardrobe" "scary_ambience" "armor_steel" "advtrains_train_industrial" "tsm_railcorridors" "steles" "homedecor_kitchen" "mobs_butterfly" "mesecons_gamecompat" "apartment" "homedecor_modpack" "worldedit" "skinsdb" "worldedit_shortcommands" "xban2" "h
2024-09-27 17:57:48: ERROR[Main]: omedecor_cobweb" "basic_materials"
2024-09-27 17:57:48: INFO[Main]: PostgreSQL Database: Version 110022 Connection made.
2024-09-27 17:57:48: INFO[Main]: PostgreSQL: Map Database was initialized.
2024-09-27 17:57:48: INFO[Main]: ServerMap: Metadata loaded from /var/games/minetest-server/.minetest/worlds/world2/
2024-09-27 17:57:48: INFO[Main]: Server: Initializing Lua
2024-09-27 17:57:48: INFO[Main]: SCRIPTAPI: Initialized game modules
2024-09-27 17:57:48: INFO[Main]: Server: Loading mods: weather sfinv mtg_craftguide creative sethome screwdriver player_api default walls stairs keys give_initial_stuff flowers butterflies fire tnt env_sounds dungeon_loot vessels fireflies carts bucket doors xpanes bones boats binoculars
2024-09-27 17:57:48: INFO[Main]: game_commands dye wool farming beds spawn map
2024-09-27 17:57:48: INFO[Main]: Mod "weather" loaded after 0 ms
2024-09-27 17:57:48: INFO[Main]: Mod "sfinv" loaded after 1 ms
2024-09-27 17:57:48: INFO[Main]: Mod "mtg_craftguide" loaded after 1 ms
2024-09-27 17:57:48: INFO[Main]: Server creating detached inventory "trash"
2024-09-27 17:57:48: INFO[Main]: Mod "creative" loaded after 2 ms
2024-09-27 17:57:48: INFO[Main]: Mod "sethome" loaded after 1 ms
2024-09-27 17:57:48: INFO[Main]: Mod "screwdriver" loaded after 0 ms
2024-09-27 17:57:48: INFO[Main]: Mod "player_api" loaded after 0 ms
2024-09-27 17:57:48: INFO[Main]: ObjDefManager: added biome: name="icesheet" index=1 uid=28
2024-09-27 17:57:48: INFO[Main]: ObjDefManager: added biome: name="icesheet_ocean" index=2 uid=39
...
...

[MrPhil]

Got it... lighting_monoid was the problem - new dependency for climate_api. Not sure why it was causing other load errors, like the Nether stuff. Definitely not the most intuitive error messages....

[Blockhead]

Got it... lighting_monoid was the problem - new dependency for climate_api. Not sure why it was causing other load errors, like the Nether stuff. Definitely not the most intuitive error messages....

What is this? About the 4th time you've posted about it to the forums after someone changed the dependencies around on you? Not to blame you at all - each time, it's always very unclear, until you check the dependencies. I wonder if you should add a check for changes to depends and optional_depends in the mod.conf to your script, so it's clear when that's changed and you can enable it.

[LMD]

I think the error message is pretty clear, though it could be a bit clearer by noting which of these are transitive failures and which ones are "root" failures (this is easy to infer however: any missing dependency that is not itself missing a dependency is a "root" one).

Note that the "configure world" GUI shows you missing dependencies in a user friendly way.

[Mantar]

This bit me too. It was a bit annoying that MT said there were no content updates waiting, and I had to find out there was a missing dependency via a crash.

[MrPhil]

Blockhead,

Actually about the 2nd time I think but I could be wrong - I didn't realize that anyone was counting... 8)

I believe that what's confusing me is probably the transitive vs root failures as LMD mentioned. Consider the following:

2024-09-27 18:00:29: ERROR[Main]: ServerError: Some mods have unsatisfied dependencies:
2024-09-27 18:00:29: ERROR[Main]: - armor_nether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - climate_api is missing: lighting_monoid
2024-09-27 18:00:29: ERROR[Main]: - regional_weather is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - livingnether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - mobs_balrog is missing: armor_nether nether
2024-09-27 18:00:29: ERROR[Main]: - nether is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - sailing_kit is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: Install and enable the required mods, or disable the mods causing errors.
2024-09-27 18:00:29: ERROR[Main]: Note: this may be caused by a dependency cycle, in which case try updating the mods.


Entries like "nether is missing: climate_api" are confusing (to me, anyway) at first glance. Nether does not depend on climate_api but I'm guessing that this happens because climate_api is an optional dependency for nether, and if it is detected as being present then it becomes a requirement. Am I on the right track here? If so, then I believe that I finally have a reasonable understanding of what's going on. If that's the case then perhaps I can avoid "strike three". xD

All joking aside though, putting a check in the script for changes to mod.conf is an excellent idea. That check could be made first with an option to abort the update if I wasn't prepared to go under the hood at that moment (this always seems to happen late at night when I am too tired and don't really have the time or inclination to start chasing down dependencies).

- Phil

Got it... lighting_monoid was the problem - new dependency for climate_api. Not sure why it was causing other load errors, like the Nether stuff. Definitely not the most intuitive error messages....

What is this? About the 4th time you've posted about it to the forums after someone changed the dependencies around on you? Not to blame you at all - each time, it's always very unclear, until you check the dependencies. I wonder if you should add a check for changes to depends and optional_depends in the mod.conf to your script, so it's clear when that's changed and you can enable it.

[Blockhead]

Blockhead,

Actually about the 2nd time I think but I could be wrong - I didn't realize that anyone was counting... 8)

I thought there was 2-3 related to xcompat plus maybe another and then this one.. Maybe you counted xcompat as one. They probably seem closer together for me because I haven't actually played all that much Minetest while you've been busy with it.

I believe that what's confusing me is probably the transitive vs root failures as LMD mentioned. Consider the following:

Code: Select all

2024-09-27 18:00:29: ERROR[Main]: ServerError: Some mods have unsatisfied dependencies:
2024-09-27 18:00:29: ERROR[Main]: - armor_nether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - climate_api is missing: lighting_monoid
2024-09-27 18:00:29: ERROR[Main]: - regional_weather is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - livingnether is missing: nether
2024-09-27 18:00:29: ERROR[Main]: - mobs_balrog is missing: armor_nether nether
2024-09-27 18:00:29: ERROR[Main]: - nether is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: - sailing_kit is missing: climate_api
2024-09-27 18:00:29: ERROR[Main]: Install and enable the required mods, or disable the mods causing errors.
2024-09-27 18:00:29: ERROR[Main]: Note: this may be caused by a dependency cycle, in which case try updating the mods.

Reading this, the thought occurs to me that the algorithm here would be to look for entries that appear only on the right-hand side of each mod pair. Those are the root(s) of the unsatisfaction.

Entries like "nether is missing: climate_api" are confusing (to me, anyway) at first glance. Nether does not depend on climate_api

Depends on whether we're talking about the nether from PilzAdam or HybridDog. ContentDB tells me the PilzAdam one does opt-depend on climate_api.

but I'm guessing that this happens because climate_api is an optional dependency for nether, and if it is detected as being present then it becomes a requirement. Am I on the right track here? If so, then I believe that I finally have a reasonable understanding of what's going on. If that's the case then perhaps I can avoid "strike three". xD

Still depending on which mod you had for my conclusion, but I thought unsatisfied dependencies always listed the next step away, the one listed in mod.conf, not any transitive dependencies (where a -> b -> c, a -> c is a transitive dependency; a is transitively dependent on c).

All joking aside though, putting a check in the script for changes to mod.conf is an excellent idea. That check could be made first with an option to abort the update if I wasn't prepared to go under the hood at that moment (this always seems to happen late at night when I am too tired and don't really have the time or inclination to start chasing down dependencies).

Go with whatever works, whether it's checking git diffs and warning you; or checking out the new state, then launching it, and finding the root of the missing dependencies with some script.

[LMD]

Reading this, the thought occurs to me that the algorithm here would be to look for entries that appear only on the right-hand side of each mod pair. Those are the root(s) of the unsatisfaction.

Yes.

but I'm guessing that this happens because climate_api is an optional dependency for nether, and if it is detected as being present then it becomes a requirement. Am I on the right track here? If so, then I believe that I finally have a reasonable understanding of what's going on. If that's the case then perhaps I can avoid "strike three". xD

Yes. When you enable an mod B which is an optional dependency for mod A, B becomes a hard dependency for A.

Still depending on which mod you had for my conclusion, but I thought unsatisfied dependencies always listed the next step away, the one listed in mod.conf, not any transitive dependencies (where a -> b -> c, a -> c is a transitive dependency; a is transitively dependent on c).

Yes, but the failure is transitive. If c is missing, b can't be loaded; if b is missing, a can't be loaded. So a can't be loaded not because a direct dependency is missing, but because a transitive dependency is missing. This will be reported as "a is missing b" and "b is missing c" of course.

[MrPhil]

That makes total sense to me then, although it would be nice if the engine kept track of whether a dependency was direct or transitive - you might be able to do it with something like an array which gets populated with the names of mods that are optional during startup and and then if there is a dependency failure, check against that array and log it with an asterisk or provide some other easily-readable output in the error log. The small amount of memory allocated to this array could then be discarded after startup is successful.

Blockhead: it is indeed PilzAdam's version of the nether mod. I didn't realize that there was another one but upon looking at both of them, I believe I'll stick with what I've got.

Thanks to everyone who weighed-in on this, hopefully this thread will help others who also find themselves asking "what the..." after updating the mods on their server.

Next, I suppose I should look into why running it from the command-line doesn't find any of the mods... might be related to the user that's running it but root should have access to everything. Also, I just noticed that it's running an earlier version of LuaJIT than the one I compiled and installed so I guess I'll need to point it to the correct library file after all, even though it said it was using the system-supplied one at compile-time, which I foolishly assumed was the newer one I had installed. Oh bother...

- Phil

[Blockhead]

Next, I suppose I should look into why running it from the command-line doesn't find any of the mods... might be related to the user that's running it but root should have access to everything.

Please don't run minetestserver as root. If someone manages an exploit on the server process (via a bad client attacking the protocol, or a trusted mod, or a malicious mod), they get full access to your system instead of just the minetest user. The way that distros run minetest is as a systemd unit with its own user. You don't have to use systemd units (but it helps with automatic restarts), but you need to set up a Minetest-specific user and know where its home directory is.

Also, I just noticed that it's running an earlier version of LuaJIT than the one I compiled and installed so I guess I'll need to point it to the correct library file after all, even though it said it was using the system-supplied one at compile-time, which I foolishly assumed was the newer one I had installed. Oh bother...

- Phil

You'll want to go over the LuaJIT-related options in compiling/README.md.

[MrPhil]

Excellent advice. I don't run MT as root in "production", I've set up an unprivileged user for that process specifically, as well as a Postgres user which only has access to the MT databases and MT does run as a systemd service - this is the case both for my private server as well as for maikerumine's madness, which is public.

You're only being paranoid if they aren't actually out to get you....

That said, I was logged in as root (yeah, I know, but typing 'sudo' over and over becomes so tiresome...) and briefly test-launched it from the command-line with the same parameters as systemd does but with info logging in order to gather more data. So it was running as root for a few seconds.

Thanks for the link. After I posted my previous reply I took another look at it and was able to fix the wrong version of LuaJIT being used at compile-time by adding: -DLUA_INCLUDE_DIR=/usr/src/luajit/src

Now it's reporting the latest LuaJit version as it should.