Closed josemmo closed 2 years ago
Proximyst
commented
3 years ago Cannot reproduce. I get intended behaviour: SIGTERM stops server without plugins (though WorldEdit and Towny apparently hook into something to still disable), and SIGINT stops the server with all plugins.
Test done with kill -SIGINT <pid> & kill -SIGTERM <pid> on Void Linux, linux package version 5.10.16_1.
How do you do your tests?
josemmo
commented
3 years ago I'm running the server on a openjdk:11-jre-slim container (Debian) with dumb-init to propagate signals.
After looking at it more thoroughly I think I've found the issue.
Plugins do not get disabled when running the paper.jar with -Dterminal.jline=false -Dterminal.ansi=true, removing these two arguments yields the desired behavior.
I don't fully understand what's going on, but it looks like it's something I'm doing wrong 😅.
Here's the container entrypoint I'm using:
#!/usr/bin/dumb-init /bin/sh
# Start other scripts in the background
# [...] &
exec java -Xms${MC_RAM} -Xmx${MC_RAM} \
-XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:MaxGCPauseMillis=200 -XX:+UnlockExperimentalVMOptions \
-XX:+DisableExplicitGC -XX:+AlwaysPreTouch -XX:G1NewSizePercent=30 -XX:G1MaxNewSizePercent=40 \
-XX:G1HeapRegionSize=8M -XX:G1ReservePercent=20 -XX:G1HeapWastePercent=5 -XX:G1MixedGCCountTarget=4 \
-XX:InitiatingHeapOccupancyPercent=15 -XX:G1MixedGCLiveThresholdPercent=90 -XX:G1RSetUpdatingPauseTimePercent=5 \
-XX:SurvivorRatio=32 -XX:+PerfDisableSharedMem -XX:MaxTenuringThreshold=1 \
-DIReallyKnowWhatIAmDoingISwear \
-Dcom.mojang.eula.agree=true \
- -Dterminal.jline=false -Dterminal.ansi=true \
-jar /app/paper.jar noguiThis is likely due to us relying on JLine's propogation, then.
Assigning to @aikar.
mikroskeem
commented
3 years ago Plugins do not get disabled when running the paper.jar with
-Dterminal.jline=false -Dterminal.ansi=true, removing these two arguments yields the desired behavior.This is likely due to us relying on JLine's propogation, then.
That's correct - when JLine is enabled, interrupt signal will be handled using it and it will shut server down gracefully
Jamie-
commented
3 years ago I'm unsure if it's directly related to this issue, but -noconsole has a similar problem.
Taking this dummy plugin as an example:
package com.example.testplugin;
import org.bukkit.plugin.java.JavaPlugin;
public class TestPlugin extends JavaPlugin {
@Override
public void onEnable() {
getLogger().info("TEST PLUGIN ENABLED");
}
@Override
public void onDisable() {
getLogger().info("TEST PLUGIN DISABLED");
}
}If I run with java -jar paper-1.16.5-529.jar both /stop and kill -SIGINT <pid> produce:
[14:17:19 INFO]: Stopping the server
[14:17:19 INFO]: Stopping server
+ [14:17:19 INFO]: [TestPlugin] Disabling TestPlugin v0.0.1
+ [14:17:19 INFO]: [TestPlugin] TEST PLUGIN DISABLED
[14:17:19 INFO]: Saving players
[14:17:19 INFO]: Saving worlds
[14:17:19 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[14:17:20 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[14:17:20 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[14:17:20 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[14:17:20 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[14:17:20 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[14:17:20 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[14:17:20 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[14:17:20 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[14:17:20 INFO]: Flushing Chunk IO
[14:17:20 INFO]: Closing Thread Pool
[14:17:20 INFO]: Closing ServerBut with java -jar paper-1.16.5-529.jar -noconsole and stopping via kill -SIGINT <pid> produces:
[14:22:24 INFO]: Stopping server
[14:22:24 INFO]: Saving players
[14:22:24 INFO]: Saving worlds
[14:22:24 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[14:22:25 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[14:22:25 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[14:22:26 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[14:22:26 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[14:22:26 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[14:22:26 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[14:22:26 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[14:22:26 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[14:22:26 INFO]: Flushing Chunk IO
[14:22:26 INFO]: Closing Thread Pool
[14:22:26 INFO]: Closing ServerThe plugin is never disabled.
mikroskeem
commented
3 years ago I'm unsure if it's directly related to this issue, but
-noconsolehas a similar problem.
Boils down to the same root cause - when you disable JLine, you won't get graceful shutdown.
Jamie-
commented
3 years ago Unless there's something I'm missing, I don't have anything to change JLine from whatever it does by default (presumably enabled?). Even adding an explicit enable: java -jar -Dterminal.jline=true paper-1.16.5-529.jar -noconsole doesn't trigger plugins to be disabled when shutdown with a SIGINT.
Edit: derp, I should have done better research, JLine is all about console input and I'm disabling it with -noconsole :facepalm: . Thanks though!
josemmo
commented
3 years ago Hi!
It's been a while since the last time I commented on this issue. I've been debugging this and here's what I've found.
Both -Dterminal.jline=false, --noconsole and --nojline trigger this bug, so most probably setting the system property "terminal.jline" to false has something to do with it. This is handled by "org.bukkit.craftbukkit.Main":
if (options.has("nojline")) {
System.setProperty(TerminalConsoleAppender.JLINE_OVERRIDE_PROPERTY, "false");
useJline = false;
}
// Paper end
if (options.has("noconsole")) {
useConsole = false;
useJline = false; // Paper
System.setProperty(TerminalConsoleAppender.JLINE_OVERRIDE_PROPERTY, "false"); // Paper
}Note TerminalConsoleAppender.JLINE_OVERRIDE_PROPERTY is a constant for "terminal.jline".
When I created this issue I thought plugins did not get disabled when sending a SIGINT/SIGTERM to the PaperMC process while running without a JLine terminal. Turns out that is not the case as plugins do get disabled but no output log is shown.
This can be verified by creating a simple plugin:
public class DebugPlugin extends JavaPlugin {
@Override
public void onEnable() {
getLogger().info("LOGGER :: DebugPlugin was enabled");
System.err.println("STDERR :: DebugPlugin was enabled");
}
@Override
public void onDisable() {
try {
getLogger().info("LOGGER :: DebugPlugin will disable in 5 seconds");
System.err.println("STDERR :: DebugPlugin will disable in 5 seconds");
Thread.sleep(1000 * 5);
getLogger().info("LOGGER :: DebugPlugin was disabled");
System.err.println("STDERR :: DebugPlugin was disabled");
} catch (Exception e) {
System.err.println("Exception when disabling DebugPlugin: " + e);
}
}
} [13:44:44 INFO]: Stopping server
+ [13:44:44 WARN]: STDERR :: DebugPlugin will disable in 5 seconds
+ [13:44:49 WARN]: STDERR :: DebugPlugin was disabled
[13:44:49 INFO]: Saving players
[13:44:49 INFO]: Saving worlds
[13:44:49 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[13:44:49 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[13:44:49 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[13:44:50 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[13:44:50 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[13:44:50 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[13:44:50 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[13:44:50 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[13:44:50 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[13:44:50 INFO]: Flushing Chunk IO
[13:44:50 INFO]: Closing Thread Pool
[13:44:50 INFO]: Closing ServerI guess this has something to do with the way plugin logger instances are created in the class "com.destroystokyo.paper.utils.PaperPluginLogger", but I'm yet to find the root cause of this bug.
I'll keep trying to figure this out, hope this post helps anyone who is looking at it aswell.
josemmo
commented
3 years ago Finally found the bug, yay!
The issue is in this line from the net.minecraft.server.MinecraftServer class:
Runtime.getRuntime().addShutdownHook(new org.bukkit.craftbukkit.util.ServerShutdownThread(this));With JLine enabled or when issuing the "/stop" command, the console calls MinecraftServer#safeShutdown(false) and then ServerShutdownThread#run() is executed, calling MinecraftServer#safeShutdown(false) again but this time doing nothing as the server has already stopped.
Without JLine, ServerShutdownThread#run() is the only method called on shutdown, and it properly tears down the server by calling MinecraftServer#safeShutdown(false). However, shutdown hooks are ran by the JVM after it calls LogManager#reset(), destroying all app loggers except for the root and resulting in no log output from plugins.
The best fix I can think of is adding a signal handler for SIGINT/SIGTERM and calling MinecraftServer#safeShutdown(false) there, similar to what PaperConsole#shutdown() does.
Is your feature request related to a problem? Please describe. When sending
SIGTERMorSIGINTto the PaperMC process, the server shuts down gracefully but without disabling plugins as would happen using the /stop command.Describe the solution you'd like Have one signal that behaves exactly as the /stop command to avoid using screen, RCON or similar workarounds. As both
SIGTERMandSIGINThave the same behavior,SIGTERMcould be left as it is andSIGINTcould be the one implementing this feature.Describe alternatives you've considered
Additional context Shutdown log using SIGTERM/SIGINT:
Shutdown log using the /stop command: