docent-net / mc-server-manager

Minecraft server manager
4 stars 0 forks source link

is 'systemctl stop' safe on a minecraft server? #45

Open gilesknap opened 4 years ago

gilesknap commented 4 years ago

It looks like minecraft server does not clean up properly when it receives a signal from systemctl. When I use manage.py to stop the server the log shows that it terminates immediately without saving the current state.

(backend) (setup) [giles@gklinux backend]$ ./manage.py start
Server secondSpigot started succesfully!
(backend) (setup) [giles@gklinux backend]$ ./manage.py stop
Server secondSpigot stopped succesfully!
(backend) (setup) [giles@gklinux backend]$ tail ../../minecraft-server/logs/latest.log
[18:24:09] [Server-Worker-3/INFO]: Preparing spawn area: 83%
[18:24:10] [Server-Worker-2/INFO]: Preparing spawn area: 83%
[18:24:10] [Server-Worker-1/INFO]: Preparing spawn area: 89%
[18:24:10] [Server thread/INFO]: Time elapsed: 2219 ms
[18:24:10] [Server thread/INFO]: Preparing start region for dimension 'world_the_end'/minecraft:the_end
[18:24:11] [Server thread/INFO]: Preparing spawn area: 0%
[18:24:11] [Server-Worker-1/INFO]: Preparing spawn area: 83%
[18:24:11] [Server thread/INFO]: Time elapsed: 744 ms
[18:24:11] [Server thread/INFO]: Server permissions file permissions.yml is empty, ignoring it
[18:24:11] [Server thread/INFO]: Done (15.658s)! For help, type "help"
(backend) (setup) [giles@gklinux backend]$

When I launch the server from the command line and then type stop it reports that it is cleaning up and saving chunks (the same output appears in latest.log).

[giles@gklinux minecraft-server]$ java -jar spigot-1.15.2.jar 
Loading libraries, please wait...
[18:26:55] [Server thread/INFO]: Starting minecraft server version 1.15.2
[18:26:55] [Server thread/INFO]: Loading properties
...
[18:27:10] [Server-Worker-3/INFO]: Preparing spawn area: 85%
[18:27:11] [Server-Worker-2/INFO]: Preparing spawn area: 98%
[18:27:11] [Server thread/INFO]: Time elapsed: 2028 ms
[18:27:11] [Server thread/INFO]: Preparing start region for dimension 'world_the_end'/minecraft:the_end
[18:27:11] [Server thread/INFO]: Preparing spawn area: 0%
[18:27:11] [Server-Worker-1/INFO]: Preparing spawn area: 83%
[18:27:12] [Server thread/INFO]: Time elapsed: 790 ms
[18:27:12] [Server thread/INFO]: Server permissions file permissions.yml is empty, ignoring it
[18:27:12] [Server thread/INFO]: Done (15.668s)! For help, type "help"
>stop
[18:27:21] [Server thread/INFO]: Stopping the server
[18:27:21] [Server thread/INFO]: Stopping server
[18:27:21] [Server thread/INFO]: Saving players
[18:27:21] [Server thread/INFO]: Saving worlds
[18:27:21] [Server thread/INFO]: Saving chunks for level 'world'/minecraft:overworld
[18:27:21] [Server thread/INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[18:27:21] [Server thread/INFO]: Saving chunks for level 'world_nether'/minecraft:the_nether
[18:27:22] [Server thread/INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[18:27:22] [Server thread/INFO]: Saving chunks for level 'world_the_end'/minecraft:the_end
[18:27:22] [Server thread/INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[18:27:22] [Server thread/INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[18:27:22] [Server thread/INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[18:27:22] [Server thread/INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
>[giles@gklinux minecraft-server]$ 

The risks are that the very latest changes to the world will not be saved, and worse that you catch it in the middle of an automatic save and corrupt some of the files.

The mitigation would be to send a stop command via RCON and wait for the server to close itself.

docent-net commented 4 years ago

Thanks, Giles. Looks like we need to improve systemd service and documentation.

Docs should mention about prerequisite, which is mcrcon client (https://github.com/Tiiffi/mcrcon) and systemd service should consist of:

ExecStop=/path/to/rcon/mcrcon -H localhost -P <some_unprivileged_port> -p <pwd> stop
KillMode=none
SuccessExitStatus=0 1
docent-net commented 4 years ago

After a deeper investigation above ExecStop might need another ExecStop to verify that server was stopped.

Sending stop command via rcon is a non-blocking command that doesn't wait until server is stopped, so possible race condition situation here:

May 07 20:39:21 minecraft java[60542]: [20:39:21] [RCON Listener #1/INFO]: RCON running on 0.0.0.0:25575                                                                                                                                      
May 07 20:40:06 minecraft systemd[37]: Stopping Minecraft Spigot server...                                             
May 07 20:40:06 minecraft java[60542]: [20:40:06] [RCON Listener #1/INFO]: Rcon connection from: /0:0:0:0:0:0:0:1      
May 07 20:40:06 minecraft java[60542]: [20:40:06] [Server thread/INFO]: [Rcon: Stopping the server]                                                                                                                                           
May 07 20:40:06 minecraft mcrcon[60932]: Stopping the server                                                                                                                                                                                  
May 07 20:40:06 minecraft systemd[37]: minecraft-server.service: Succeeded.                                                                                                                                                                   
May 07 20:40:06 minecraft systemd[37]: Stopped Minecraft Spigot server.                                                                                                                                                                       May 07 20:40:06 minecraft java[60542]: [20:40:06] [Server thread/INFO]: Stopping server                                
May 07 20:40:06 minecraft java[60542]: [20:40:06] [Server thread/INFO]: Saving players                                                                                                                                                        
May 07 20:40:06 minecraft systemd[37]: minecraft-server.service: Found left-over process 60542 (java) in control group while starting unit. Ignoring.
May 07 20:40:06 minecraft systemd[37]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
May 07 20:40:06 minecraft systemd[37]: Started Minecraft Spigot server.                                                
May 07 20:40:06 minecraft java[60542]: [20:40:06] [Server thread/INFO]: Saving worlds                                                                                                                                                         
May 07 20:40:06 minecraft java[60542]: [20:40:06] [Server thread/INFO]: Saving chunks for level 'world'/minecraft:overworld
May 07 20:40:07 minecraft java[60936]: *** Error, this build is outdated ***                                                                                                                                                                  
May 07 20:40:07 minecraft java[60936]: *** Please download a new build as per instructions from https://www.spigotmc.org/go/outdated-spigot ***                                                                                               
May 07 20:40:07 minecraft java[60936]: *** Server will start in 20 seconds ***                                         
May 07 20:40:07 minecraft java[60542]: [20:40:07] [Server thread/INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved

So maybe instead of invoking rcon via ExecStop there could be a wrapper, that invokest this rcon/stop and then pools for the status and wait until the server is stopped?

gilesknap commented 4 years ago

I have in mind a little python app that can connect to rcon and provide a way to send server commands (with some auto-completion like I currently have in my solution). It would be easy to add an argument to the CLI to ask it to send a stop and wait for shutdown. We could the call that in ExecStop

docent-net commented 4 years ago

Giles, one of the future features of mc-server-manager is actually communication via console w/mc-server. And rcon is a great solution. That's why instead of a standalone script, mc-server-manager could integrate and expose rcon communication as it will use this in UI.

So I'm thinking about a communication layer in mc-server-manager, that could be exposed to manager.py (and possibly API server).

In practice, for this issue of stopping the server, the flow could look like:

  1. manage.py stop sends stop via the rcon to mc server and waits until the server is stopped
  2. when the server is stopped by rcon command, manage.py continues stopping process by calling stop on systemd service via DBUS
  3. and now service should be stopped properly :)
gilesknap commented 4 years ago

This is all good. It seems mc-server-manager is planning to implement every requirement I have.

Let me know if there is a discrete piece of functionality that you would like me to contribute.

docent-net commented 4 years ago

Giles, actually anything you'd like to work on will be cool :) There's plenty of work so just take a look around :) Introductory issues are tagged with 'good-first-issue' or something similar. But of course you can take anything :) Just let me know so I can assign yourself so we don't do the same thing twice :) Thanks!