MineOS-node restarting server resets runnable jar


#1

I have a scheduled task that restarts my servers every other day. Whenever it runs the server stops but does not start back up again. Restarting it manually usually works, and restarting it from the command also usually works. Is this a bug that can be fixed or is there something I’m missing?


#2

Why restart them at all?


#3

Because the ram usage builds up over time despite the fact I have garbage collecting enabled.


#4

There are several memory related threads on this forum. This is a nice collector thread: Minecraft Server Memory Leak

TLDR: Your memory usage builds up because minecraft loads world chunks into memory to make the server quicker. Free memory is unused memory, and thus also wasted memory. Trust your OS th handle memory, unless you are actually having memory issues.

Or as @hexparrot said it (in an answer to someone else) :

Question: if you’re okay allocating 7282 MB of RAM to Minecraft, why would you want Minecraft using any less than that?
Good performance comes from Minecraft having and utilizing lots of available RAM, not from having and reserving unused RAM.


#5

Yeah I think I’ll look into that. However this bug of restarting servers shouldn’t go unnoticed. I just decided to restart both of my servers manually and somehow the runnable jar file was reset again. There’s no point in restarting if it’s the same as stopping and starting again. It’s getting pretty annoying to have to specify the jar file every time. So some help with this bug would be much appreciated.


#6

Lacking logs or errors that will make us able to hunt down this bug, I can only come with general advice:

The first thing to check then is if the file “server.config” is writable to the user running your minecraft server (usually “mc”, that user will be used by me from now. Substitue with your own user if needed, just not “root”).

If it is owned user and group by “root” you have an access problem with that file, that means MineOS cant write this setting to your file:
jarfile={minecraft server filename}.jar

(This also points to a workaround: add your chosen jar file to that setting manually and save. As long as you do not touch the jar selector dropdown, that setting wil stay set even though it looks unset in MineOS).

Now, if the file is owned by user:group root, this means the root user was probably used to create the server, this leads to unpredictalbe behaviour, and unstable server, as a lot of needed files gets write protected, or unaccessible. To fix this make an archive of the server, delete the server, then import it from the archive as the mc user. This makes sure all files get the correct user and group ownership. Never user “root” on your server unless absolutely needed (for OS and MineOS updates).

Now, if you feel that none of that apply to you (you have confirmed that the file mentioned are writable by “mc”, and that the server was not made by “root”) we will need some logs to be able to help further.

You have (at least) two logs that may contain traces that can help us find your bug:
/var/log/mineos.log (The log for MineOS itself)
/var/games/servers/(servername)/logs/latest.log (the log for your minecraft server).


#7

If it’s a bug, you’ll need to provide at least some information so that I can reproduce it.

Here’s what happens when I attempt a restart on a fresh 1.12.2:

[16:16:57] [Server thread/INFO]: Starting minecraft server version 1.12.2
[16:16:57] [Server thread/WARN]: To start the server with more ram, launch it as "java -Xmx1024M -Xms1024M -jar minecraft_server.jar"
[16:16:57] [Server thread/INFO]: Loading properties
[16:16:57] [Server thread/INFO]: Default game type: SURVIVAL
[16:16:57] [Server thread/INFO]: Generating keypair
[16:16:57] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
[16:16:57] [Server thread/INFO]: Using epoll channel type
[16:16:57] [Server thread/INFO]: Preparing level "world"
[16:16:58] [Server thread/INFO]: Loaded 488 advancements
[16:16:59] [Server thread/INFO]: Preparing start region for level 0
[16:17:00] [Server thread/INFO]: Preparing spawn area: 5%
[16:17:01] [Server thread/INFO]: Preparing spawn area: 9%
[16:17:02] [Server thread/INFO]: Preparing spawn area: 12%
[16:17:03] [Server thread/INFO]: Preparing spawn area: 17%
[16:17:04] [Server thread/INFO]: Preparing spawn area: 23%
[16:17:05] [Server thread/INFO]: Preparing spawn area: 30%
[16:17:06] [Server thread/INFO]: Preparing spawn area: 37%
[16:17:07] [Server thread/INFO]: Preparing spawn area: 45%
[16:17:08] [Server thread/INFO]: Preparing spawn area: 53%
[16:17:09] [Server thread/INFO]: Preparing spawn area: 61%
[16:17:10] [Server thread/INFO]: Preparing spawn area: 70%
[16:17:11] [Server thread/INFO]: Preparing spawn area: 79%
[16:17:12] [Server thread/INFO]: Preparing spawn area: 88%
[16:17:13] [Server thread/INFO]: Preparing spawn area: 98%
[16:17:13] [Server thread/INFO]: Done (15.806s)! For help, type "help" or "?"
[16:17:17] [Server thread/INFO]: Stopping the server
[16:17:17] [Server thread/INFO]: Stopping server
[16:17:17] [Server thread/INFO]: Saving players
[16:17:17] [Server thread/INFO]: Saving worlds
[16:17:17] [Server thread/INFO]: Saving chunks for level 'world'/overworld
[16:17:18] [Server thread/INFO]: Saving chunks for level 'world'/the_nether
[16:17:18] [Server thread/INFO]: Saving chunks for level 'world'/the_end
[16:17:23] [Server thread/INFO]: Starting minecraft server version 1.12.2
[16:17:23] [Server thread/WARN]: To start the server with more ram, launch it as "java -Xmx1024M -Xms1024M -jar minecraft_server.jar"
[16:17:23] [Server thread/INFO]: Loading properties
[16:17:23] [Server thread/INFO]: Default game type: SURVIVAL
[16:17:23] [Server thread/INFO]: Generating keypair
[16:17:23] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
[16:17:23] [Server thread/INFO]: Using epoll channel type
[16:17:23] [Server thread/INFO]: Preparing level "world"
[16:17:24] [Server thread/INFO]: Loaded 488 advancements
[16:17:24] [Server thread/INFO]: Preparing start region for level 0
[16:17:25] [Server thread/INFO]: Preparing spawn area: 8%
[16:17:26] [Server thread/INFO]: Preparing spawn area: 84%
[16:17:26] [Server thread/INFO]: Done (2.534s)! For help, type "help" or "?"

and here’s how it’s handled from the back end.

{"command":"create","server_name":"asdf","properties":{"generate-structures":true},"level":"info","message":"[WEBUI] Received emit command from 1.29.115.215:mc","timestamp":"2018-05-24T16:16:42.202Z"}
{"level":"info","message":"[asdf] Discovered server","timestamp":"2018-05-24T16:16:42.210Z"}
{"level":"error","message":"[asdf] Create tail on logs/latest.log failed","timestamp":"2018-05-24T16:16:42.213Z"}
{"level":"info","message":"[asdf] Watching for file generation: logs/latest.log","timestamp":"2018-05-24T16:16:42.213Z"}
{"level":"error","message":"[asdf] Create tail on server.log failed","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"info","message":"[asdf] Watching for file generation: server.log","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"error","message":"[asdf] Create tail on proxy.log.0 failed","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"info","message":"[asdf] Watching for file generation: proxy.log.0","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"error","message":"[asdf] Create tail on logs/fml-server-latest.log failed","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"info","message":"[asdf] Watching for file generation: logs/fml-server-latest.log","timestamp":"2018-05-24T16:16:42.214Z"}
{"level":"info","message":"[asdf] Using skipDirEntryPatterns: world,world_the_end,world_nether,dynmap,plugins,web,logs,region,playerdata,stats,data","timestamp":"2018-05-24T16:16:42.215Z"}
{"level":"info","message":"[asdf] mc (1.29.115.215) joined server namespace","timestamp":"2018-05-24T16:16:42.243Z"}
{"level":"info","message":"[asdf] Server created in filesystem.","timestamp":"2018-05-24T16:16:42.247Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"modify_sc\"","timestamp":"2018-05-24T16:16:44.690Z"}
{"level":"info","message":"[asdf] received request \"modify_sc\"","timestamp":"2018-05-24T16:16:44.693Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"accept_eula\"","timestamp":"2018-05-24T16:16:46.238Z"}
{"level":"info","message":"[asdf] received request \"accept_eula\"","timestamp":"2018-05-24T16:16:46.238Z"}
{"level":"info","message":"[asdf] eula.txt detected: ACCEPTED (eula=true)","timestamp":"2018-05-24T16:16:46.694Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"modify_sc\"","timestamp":"2018-05-24T16:16:49.817Z"}
{"level":"info","message":"[asdf] received request \"modify_sc\"","timestamp":"2018-05-24T16:16:49.817Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"modify_sc\"","timestamp":"2018-05-24T16:16:51.269Z"}
{"level":"info","message":"[asdf] received request \"modify_sc\"","timestamp":"2018-05-24T16:16:51.270Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"start\"","timestamp":"2018-05-24T16:16:52.765Z"}
{"level":"info","message":"[asdf] received request \"start\"","timestamp":"2018-05-24T16:16:52.765Z"}
{"level":"info","message":"[asdf] latest.log created! Watchfile logs/latest.log closed","timestamp":"2018-05-24T16:16:55.676Z"}
{"level":"info","message":"[asdf] Created tail on logs/latest.log","timestamp":"2018-05-24T16:16:55.677Z"}
{"level":"info","message":"[asdf] 1.29.115.215 issued command : \"restart\"","timestamp":"2018-05-24T16:17:17.845Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T16:17:17.845Z"}
~

The timestamps line up: it receives the restart command and it stops, then starts the server again.

As far as I can tell, the restart functionality works as expected. If it is not working for you, then perhaps it is a MineOS bug, or perhaps it’s a permissions issue or perhaps it’s whatever non-vanilla server you’re using…but we’ll need more information before I can fix anything, unfortunately.


#8

Here is the error message from /var/log/mineos.log

[server] received request \"restart\"","timestamp":"2018-05-21T04:00:00.342Z"}
{"command":"restart","source":"0 0 */2 * *","msg":"","enabled":true,"success":false,"err":"up","time_resolved":1526875200351,"level":"error","message":"[server] command \"restart\" errored out:","timestamp":"2018-05-21T04:00:00.351Z"}
{"level":"info","message":"[server2] received request \"restart\"","timestamp":"2018-05-21T04:00:00.559Z"}
{"command":"restart","source":"0 0 */2 * *","msg":"","enabled":true,"success":false,"err":"Cannot start server without a designated jar/phar.","time_resolved":1526875201736,"level":"error","message":"[server2] command \"restart\" errored out:","timestamp":"2018-05-21T04:00:01.736Z"}

It seems as though the error was as expected when there is no specified jar. So I checked server.config and sure enough it wasn’t there. The mc account has read and write access as well as some execute access to the /var/games/minecraft subdirectories. The mc account is owner on everything within it as well. I created the server with the mc account too. Since each time I tried specifying a jar for my server within the webui I used the mc account to manually edit the server.config file.


#9

Hrm, just ran two separate servers each restarting minutely, and they kept up:

{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:45:00.115Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:45:00.384Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:46:00.121Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:46:00.384Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:47:00.122Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:47:00.385Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:48:00.118Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:48:00.389Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:49:00.121Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:49:00.388Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:50:00.120Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:50:00.387Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:51:00.122Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:51:00.390Z"}
{"level":"info","message":"[ffff] received request \"restart\"","timestamp":"2018-05-24T22:52:00.123Z"}
{"level":"info","message":"[asdf] received request \"restart\"","timestamp":"2018-05-24T22:52:00.388Z"}

Next question:

  1. what server profile/jar are you using?
  2. how is this server profile/jar normally stopped? (“stop” or something else)
  3. does the ‘restart’ button work in ‘server status’ (its in the triangle dropdown in the red stop button)
  4. what commit are you using? (the value when you click on the triangle next to your name at the top).

Full logs are more helpful than curated ones, for future reference.