Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Excessive RAM usage with Animalia (memory leak ?) #94

Open
BarbeRousseLibre opened this issue May 16, 2024 · 10 comments
Open

Excessive RAM usage with Animalia (memory leak ?) #94

BarbeRousseLibre opened this issue May 16, 2024 · 10 comments

Comments

@BarbeRousseLibre
Copy link

Hello,

I detected what could be a memory leak in this mod. But I'm not a dev and prefer to stay factual:

Running 5.8.0 minetestserver, with other mods, I had a big problem with ram usage.

Animalia makes the server use more than 40Gb, while I have 16Gb of RAM and 16Gb of SWAP.

  • Host: Gentoo, hardened profile, 23.0, amd64.
  • Kernel: Linux Mephistopheles 6.6.30-gentoo-dist-hardened
  • Server and client are on the same host.

Minetest & minetestserver were compiled from Gentoo ebuild repository : https://packages.gentoo.org/packages/games-engines/minetest

I know it does not come from my client, but minetestserver because even if I play on the same workstation that is running the server, so it's on the same machine minetestserver (runned from command line) + client, if another players joins but I don't, the problem is the same.

The server started to act weird, slow, and it was a very huge amount of RAM usage from minetestserver. After disabling mod one after each other, it does not happens without Animalia, and don't act again with all other mods enabled (without Animalia).

It started with a sudden heavy RAM usage after ~1h of playing with Animalia, then, every time the server was restarted and exactly when a new player join (me or another), the amount of RAM explode: In less than 10 seconds it used already almost my 16Gb and was starting to write quickly into swap, slowing the whole system.

Also, if the server is empty, I was able to run it for 8 hours straight without a single problem, but once someone join, it use this huge amount of RAM in seconds.

To shows how fast and critical this is, below some extract of a simple bash script taking the amount of ram used by minetestserver every 5 seconds. It start to act very quicky:

Server is running, empty:
15-05-2024 19:28:17

   254.02 Mb minetestserver 

Then, a player come:

15-05-2024 19:28:22

   361.14 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:27

  1339.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:32

  4027.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:37

  7611.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:42

 21947.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:47

 21947.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:52

 14779.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

--- * --- * --- * ---

--- * --- * --- * ---

15-05-2024 19:28:57

 43451.32 Mb minetestserver 
     0.52 Mb grep minetestserver 

As you can see, it's increasing very quickly, but sometimes it goes down a bit (from 21Gb to 14, then 43…).

I have to Gatling the Ctrl^C keys to turn it off, otherwise it can hangs for a while until the system finally drop the SWAP and RAM usage. Sometimes I had to kill the minetestserver process with kill -9, otherwise it was non-effective.

I'm not use to do bug report, so please if you need more files, informations or test, ask me, will be glad to help.

Regards,
GASPARD DE RENEFORT Kévin

@appgurueu
Copy link

Can you determine whether this high memory usage happens in the engine or in Lua? I would like to know what collectgarbage("count") gives you.

@BarbeRousseLibre
Copy link
Author

Hello and thanks for your interest,

How I am supposed to use this string ? Where should I put it ? In the minetestserver console ? In the in-game console ?

After a quick research, it seems to be a LUA function, maybe then I should add it into some .lua file ? If that's the case, which one ?

Regards,
GASPARD DE RENEFORT Kévin

@appgurueu
Copy link

appgurueu commented May 16, 2024

Yes, this is a Lua function. Its return value tells you how much memory Lua is currently using. You could put this in a mod which logs it periodically, say, once a minute. So something like

local function log_memory_usage()
    minetest.log("info", "Lua memory usage: " .. collectgarbage("count") .. " Kb")
    minetest.after(60 --[[once a minute]], log_memory_usage)
end
minetest.register_on_mods_loaded(log_memory_usage)

this can be put in a fresh mod, say logmem, then used as the mod's init.lua.

@BarbeRousseLibre
Copy link
Author

I tried to add a directory inside /home/minetestserver/.minetest/mods/logmem, inside I added to init.lua your code, and then modified it for 20 seconds (I'm not patient), it was also added to world.mt the line «load_mod_logmen = true».

But no luck, I can' find anything:

«tail -f Minetest/logs/testAvecJustine.log | grep "Lua memory usage:"»

Just output nothing (this file is the log of the server), as using grep myself, but I see this in the log:

«2024-05-16 22:30:17: WARNING[Main]: Mod logmem at /home/minetestadmin/.minetest/mods/logmem:
2024-05-16 22:30:17: WARNING[Main]: Mods not having a mod.conf file with the name is deprecated.»

Which I guess is not that important. Simply saying «it's not a good thing», but it should works, right ? Did I missed something in your steps ?

Regards,
GASPARD DE RENEFORT Kévin

@appgurueu
Copy link

Which I guess is not that important. Simply saying «it's not a good thing», but it should works, right ? Did I missed something in your steps ?

Yes, it should work. I assume your debug_log_level is set too high. You could either set your debug_log_level to info or increase the log level in the code snippet I sent to something higher, like warning.

@BarbeRousseLibre
Copy link
Author

Changed the line in the init.lua inside the logmem directory, it was the level indeed, thanks.

So, after some hours on a fresh game, it happened again. First output is my own bash to retrieve the actual memory usage of the minetestserver process:

--- * --- * --- * ---

18-05-2024 00:15:37 

       909.19 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:15:42 

      6285.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:15:47 

     11661.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:15:52 

      8077.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:15:57 

     22413.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:16:03 

     22413.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:16:08 

     22413.20 Mb minetestserver 
         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:16:13 

         0.52 Mb grep minetestserver 
         0.00 Mb [minetestserver] <defunct> 

 --- * --- * --- * ---

--- * --- * --- * ---

18-05-2024 00:16:18 

         0.52 Mb grep minetestserver 

 --- * --- * --- * ---

Then, the output of the server at the same time (minus 1 minute) until I shut it down violently before it crash anything:

2024-05-18 00:14:38: WARNING[Server]: Lua memory usage: 157485.45800781 Kb
2024-05-18 00:14:38: ACTION[Server]: Justine digs flowers:dandelion_yellow at (321,38,6)
2024-05-18 00:14:40: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:14:40: ERROR[Server]: LuaEntity name "wildlife:wolf" not defined
2024-05-18 00:14:43: ACTION[Server]: Justine digs flowers:dandelion_white at (324,42,14)
2024-05-18 00:14:44: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:14:44: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:14:44: ERROR[Server]: LuaEntity name "wildlife:wolf" not defined
2024-05-18 00:14:46: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:14:52: ACTION[Server]: [Creatura] [ABM Spawning] Spawned 3 animalia:cow at (291,55,46)
2024-05-18 00:14:52: ERROR[Server]: LuaEntity name "wildlife:wolf" not defined
2024-05-18 00:14:56: ACTION[Server]: [Creatura] [ABM Spawning] Spawned 8 animalia:song_bird at (307,20,68)
2024-05-18 00:14:56: ACTION[Server]: [Creatura] [ABM Spawning] Spawned 11 animalia:song_bird at (264,64,36)
2024-05-18 00:14:57: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:14:57: ACTION[Server]: Justine digs footprints:dirt_with_grass at (316,43,14)
2024-05-18 00:14:58: WARNING[Server]: Lua memory usage: 117928.79882812 Kb
2024-05-18 00:14:58: ACTION[Server]: Justine digs default:dirt_with_grass at (317,43,14)
2024-05-18 00:14:59: ACTION[Server]: Justine digs default:dirt_with_grass at (317,43,15)
2024-05-18 00:15:00: ACTION[Server]: Justine digs default:dirt_with_grass at (318,43,15)
2024-05-18 00:15:01: ACTION[Server]: Justine digs default:dirt_with_grass at (317,43,16)
2024-05-18 00:15:02: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,15)
2024-05-18 00:15:02: ACTION[Server]: Justine digs footprints:dirt_with_grass at (315,43,15)
2024-05-18 00:15:03: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,16)
2024-05-18 00:15:04: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,17)
2024-05-18 00:15:05: ACTION[Server]: Justine digs default:dirt_with_grass at (317,43,17)
2024-05-18 00:15:06: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,18)
2024-05-18 00:15:08: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,17)
2024-05-18 00:15:08: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:09: ACTION[Server]: Justine digs footprints:dirt_with_grass at (315,43,16)
2024-05-18 00:15:10: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,16)
2024-05-18 00:15:10: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,17)
2024-05-18 00:15:11: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,17)
2024-05-18 00:15:12: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,18)
2024-05-18 00:15:13: ACTION[Server]: Justine digs default:grass_3 at (313,44,18)
2024-05-18 00:15:14: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,18)
2024-05-18 00:15:15: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,19)
2024-05-18 00:15:16: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,18)
2024-05-18 00:15:17: ERROR[Server]: LuaEntity name "wildlife:wolf" not defined
2024-05-18 00:15:17: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,19)
2024-05-18 00:15:18: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,19)
2024-05-18 00:15:18: WARNING[Server]: Lua memory usage: 132965.17675781 Kb
2024-05-18 00:15:18: ACTION[Server]: Justine digs default:dirt_with_grass at (316,43,20)
2024-05-18 00:15:19: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,20)
2024-05-18 00:15:20: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,21)
2024-05-18 00:15:21: ACTION[Server]: Justine digs default:dirt_with_grass at (315,43,22)
2024-05-18 00:15:22: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,21)
2024-05-18 00:15:23: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,22)
2024-05-18 00:15:24: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,22)
2024-05-18 00:15:25: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:25: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,21)
2024-05-18 00:15:26: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,20)
2024-05-18 00:15:27: ACTION[Server]: Justine digs default:dirt_with_grass at (313,43,20)
2024-05-18 00:15:28: ACTION[Server]: Justine digs default:dirt_with_grass at (314,43,19)
2024-05-18 00:15:28: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:28: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:28: ERROR[Server]: LuaEntity name "wildlife:wolf" not defined
2024-05-18 00:15:37: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:37: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:37: ERROR[Server]: LuaEntity name "wildlife:deer" not defined
2024-05-18 00:15:37: ACTION[Server]: Justine places node default:dirt at (307,45,16)
2024-05-18 00:15:38: WARNING[Server]: Lua memory usage: 155687.82617188 Kb
^X^X^X^X^C2024-05-18 00:16:11: [Main]: INFO: signal_handler(): Ctrl-C pressed, shutting down.
^C^C^C^C^C^C^C^C^C

You'll see a lot of warning about wildlife:deer not defined, because I disabled it. In my opinion it's probably nothing because it happened the same way, on our last game, with that mod enabled. I might be delusional and not skilled to be factual about that tho.

If needed, please ask. Good luck.

Regards,
GASPARD DE RENEFORT Kévin

@appgurueu
Copy link

It looks like Lua memory usage is not the culprit. This means it's probably an engine issue that is merely brought to light by Animalia; or Animalia is somehow forcing the engine to use absurd amounts of memory.

If this really is an engine memory leak where memory is not freed at all, you should be able to detect it by compiling with a leak sanitizer: When Minetest shuts down, this should then report any memory leaks (note that there are some smaller leaks, but we're after a big leak here).

Compiling with a leak sanitizer can be achieved by passing -DCMAKE_CXX_FLAGS="-fsanitize=leak" when configuring via cmake.

@BarbeRousseLibre
Copy link
Author

Hello,

I managed to compile minetest with the CXX_FLAGS you asked for, at least it seems like. No options (aka USE FLAG in Gentoo) was changed, the only change should be the addition of that CXX_FLAGS.

Here a quick test to see if it has enabled it, I'm not the best for these matters but it looks like it was enabled.

 Mephistopheles /var/tmp # grep -rin "fsanitize=leak" portage/games-engines/minetest-5.8.0/
portage/games-engines/minetest-5.8.0/temp/environment:53:declare -x DCMAKE_CXX_FLAGS="-fsanitize=leak"

So, from here, how it'll help us see if there is a problem on memory leaking from the engine ?

Does this will print information into the server console, or into some file somewhere ?

Maybe it is used only for the building and should be able to see the build.log for this ?

Regards,
GASPARD DE RENEFORT Kévin

@BobOmbuzal
Copy link

I've got the same problem with https://github.com/ElCeejo/draconis
Maybe the problem is in https://github.com/ElCeejo/creatura because both use this API?

@ElCeejo is probably lost in real life? Maybe more https://www.patreon.com/ElCeejo would help?

@appgurueu
Copy link

So, from here, how it'll help us see if there is a problem on memory leaking from the engine ? Does this will print information into the server console, or into some file somewhere ?

Yes. This checks whether Minetest is leaking memory by allocating it and never freeing it, not even at program shutdown. This will not catch all leaks (for example, there might be a "run-time" leak, where the memory is still freed when Minetest is exited), but it catches many leaks. The output should be in the server console after Minetest has shut down.

Another thing you could try would be to git bisect creatura / draconis / animalia. This would probably be a bit painful though, since each time you try a new version of creatura, you would have to make sure to check out the corresponding commit of draconis or animalia (though a script going by date could probably help with that). Older releases crashing or similar may add to the issue(s).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants