Bug Report: skinsdb mod assertion failure on recent version.

[Lazerbeak12345]

Problem

This error is logged in the server

2024-07-17 18:21:55.658572216 2024-07-17 18:21:55: ERROR[Main]: .../.minetest/games/whynot-game/mods/player/skinsdb/api.lua:79: attempt to index local 'file' (a nil value) 2024-07-17 18:21:55.658573814 2024-07-17 18:21:55: ERROR[Main]: stack traceback: 2024-07-17 18:21:55.658575368 2024-07-17 18:21:55: ERROR[Main]: .../.minetest/games/whynot-game/mods/player/skinsdb/api.lua:79: in function 'get_skin_format' 2024-07-17 18:21:55.658584492 2024-07-17 18:21:55: ERROR[Main]: ...etest/games/whynot-game/mods/player/skinsdb/skinlist.lua:78: in function 'register_skin' 2024-07-17 18:21:55.658585940 2024-07-17 18:21:55: ERROR[Main]: ...etest/games/whynot-game/mods/player/skinsdb/skinlist.lua:145: in main chunk 2024-07-17 18:21:55.658593886 2024-07-17 18:21:55: ERROR[Main]: [C]: in function 'dofile' 2024-07-17 18:21:55.658601976 2024-07-17 18:21:55: ERROR[Main]: ....minetest/games/whynot-game/mods/player/skinsdb/init.lua:13: in main chunk

From going over the source, it is failing to open one of the files that I have had on my server for a few years, and completely bailing out instead.

Once I can get into my server, I can find exactly which filename/pathname is the culprit, and I'll include that here.

Steps to reproduce

latest version, launch server

Expected behavior

The server should start instead of asserting.

Minetest client version

Minetest 5.8.0 (Linux) (5.8.0-2)

Downstream issue:

https://github.com/minetest-whynot/whynot-game/issues/196

[Lazerbeak12345]

After attemping to recreate this, it is not happening right now. I have a few more things I could try, but it's the exact same server, world, version of everything, etc. the only difference was setting the debug var to true. oh, and the server has restarted

I'm not sure if you want this issue open or not...

[Lazerbeak12345]

Alright, I got it to happen again. I had to restart the whole server (as opposed to the service).

[Lazerbeak12345]

It seems that it could be a latency issue? Logging can take some amount of CPU, and when it's logging, it doesn't happen.

[SmallJoker]

This code is run on init. I find it strange that this part would depend on timing at all, as it blocks the server thread entirely. Please try to gather more information by logging the failing file:

diff --git a/skinlist.lua b/skinlist.lua
index a2d4a27..98bbe8e 100644
--- a/skinlist.lua
+++ b/skinlist.lua
@@ -74,10 +74,14 @@ function skins.register_skin(path, filename)

        if path then
                -- Get type of skin based on dimensions
-               local file = io.open(path .. "/" .. filename, "r")
+               local file, msg = io.open(path .. "/" .. filename, "r")
+               if not file then
+                       minetest.log("error", "tried to open file '" .. path .. "/" .. filename .. "'. Error: " .. msg)
+               else
                local skin_format = skins.get_skin_format(file)
                skin_obj:set_meta("format", skin_format)
                file:close()
+               end
        end

        skin_obj:set_hand_from_texture()

[Lazerbeak12345]

Giving that a try now. So far, with that patch, the issue hasn't happened yet. I'll be restarting the server/service a few times to see if I can get it to happen with this logging feature

[Lazerbeak12345]

I got it!

2024-07-20 09:45:53.047511020  2024-07-20 09:45:53: ERROR[Main]: tried to open file '/var/lib/minetest/.minetest/games/whynot-game/mods/player/skinsdb/textures/character_1207.png'. Error: /var/lib/minetest/.minetest/games/whynot-game/mods/player/skinsdb/textures/character_1207.png: Too many open files

Got a few hundred of these.

[Lazerbeak12345]

Perhaps adding support in skinsdb for joined player textures using Minetest's offset and cropping tools (that are applied to filenames) would make for one solution? There are a LOT of mods on this server (so therefore a lot of files to load)

[SmallJoker]

Too many open files

This means that the garbage collector is too slow and ulimit -n is somewhat low. Please keep in mind that all skin textures are sent to clients, resulting in very long join times. Perhaps this could be solved by using dynamic media in a future PR.

About your issue: Please try the following changes. If those do not help, do increase the file descriptor limit for the Minetest process.

diff --git a/skinlist.lua b/skinlist.lua
index a2d4a27..5330c7b 100644
--- a/skinlist.lua
+++ b/skinlist.lua
@@ -92,6 +92,7 @@ function skins.register_skin(path, filename)
                        skin_obj:set_meta("name", data[1])
                        skin_obj:set_meta("author", data[2])
                        skin_obj:set_meta("license", data[3])
+                       file:close()
                end
        end

@@ -102,6 +103,7 @@ function skins.register_skin(path, filename)
                if fh then
                        dbgprint("Found preview", preview_name)
                        skin_obj:set_preview(preview_name)
+                       fh:close()
                end
        end

[Lazerbeak12345]

manually closing the files, as in your last comment seems to have done the task.

So far, my total diff is this (minding different filenames):

diff --git a/mods/player/skinsdb/skinlist.lua b/mods/player/skinsdb/skinlist.lua
index a2d4a27..b5208b0 100644
--- a/mods/player/skinsdb/skinlist.lua
+++ b/mods/player/skinsdb/skinlist.lua
@@ -74,10 +74,14 @@ function skins.register_skin(path, filename)

        if path then
                -- Get type of skin based on dimensions
-               local file = io.open(path .. "/" .. filename, "r")
-               local skin_format = skins.get_skin_format(file)
-               skin_obj:set_meta("format", skin_format)
-               file:close()
+               local file, msg = io.open(path .. "/" .. filename, "r")
+               if not file then
+                       minetest.log("error", "tried to open file '" .. path .. "/" .. filename .. "'. Error: " .. msg)
+               else
+                       local skin_format = skins.get_skin_format(file)
+                       skin_obj:set_meta("format", skin_format)
+                       file:close()
+               end
        end

        skin_obj:set_hand_from_texture()
@@ -92,6 +96,7 @@ function skins.register_skin(path, filename)
                        skin_obj:set_meta("name", data[1])
                        skin_obj:set_meta("author", data[2])
                        skin_obj:set_meta("license", data[3])
+                       file:close()
                end
        end

@@ -102,6 +107,7 @@ function skins.register_skin(path, filename)
                if fh then
                        dbgprint("Found preview", preview_name)
                        skin_obj:set_preview(preview_name)
+                       fh:close()
                end
        end

[SmallJoker]

Fixed in df62f20. The error handling code is not included because every file open call would need such handling, as it may appear at a random location, or random mod.

Please let me know in case this error reappears. If there's other mods that read/write to many different files, they will need a similar fix as well.