search

PaperMC / Paper

The most widely used, high performance Minecraft server that aims to fix gameplay and mechanics inconsistencies
https://papermc.io/
Other
9.99k stars 2.32k forks source link

Server doesn't behave like expected when piping commands #7126

Closed Simonesien closed 2 years ago

Simonesien commented 2 years ago

Expected behavior

I want the Server to start, process the piped input and therefore shutting down.

Observed/Actual behavior

The Server printed ServerMain WARN Advanced terminal features are not available in this environment on start and simply didn't shut down after processing the piped 'stop' printing this error:

Log4j2-AsyncAppenderEventDispatcher-1-Async WARN Advanced terminal features are not available in this environment

By using the command java -jar server.jar nogui < file_with_word__stop__in_it, it did the same, but didn't print the above error, but an error about Thread Death.

Steps/models to reproduce

Install Paper 1.18.1 and start the Server with the command echo "stop" | java -jar server.jar nogui.

Plugin and Datapack List

Nothing

Paper version

This server is running Paper version git-Paper-68 (MC: 1.18.1) (Implementing API version 1.18.1-R0.1-SNAPSHOT) (Git: 1c779c2)

Other

No response

electronicboy commented 2 years ago 
$ echo stop | java -jar paper-1.18.1-76.jar
Downloading mojang_1.18.1.jar
Applying patches
Starting org.bukkit.craftbukkit.Main
System Info: Java 17 (OpenJDK 64-Bit Server VM 17.0.1+12) Host: Mac OS X 10.16 (x86_64)
Loading libraries, please wait...
2021-12-15 16:38:24,311 ServerMain WARN Advanced terminal features are not available in this environment
[16:38:29 ERROR]: Failed to load properties from file: server.properties
[16:38:29 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
[16:38:29 INFO]: Found new data pack file/bukkit, loading it automatically
[16:38:30 INFO]: Reloading ResourceManager: Default, bukkit
[16:38:30 INFO]: Loaded 7 recipes
[16:38:34 INFO]: Starting minecraft server version 1.18.1
[16:38:34 INFO]: Loading properties
[16:38:34 INFO]: This server is running Paper version git-Paper-76 (MC: 1.18.1) (Implementing API version 1.18.1-R0.1-SNAPSHOT) (Git: 95d881f)
[16:38:34 INFO]: Server Ping Player Sample Count: 12
[16:38:34 INFO]: Using 4 threads for Netty based IO
[16:38:34 INFO]: Default game type: SURVIVAL
[16:38:34 INFO]: Generating keypair
[16:38:35 INFO]: Starting Minecraft server on *:25565
[16:38:35 INFO]: Using default channel type
[16:38:35 INFO]: Paper: Using Java 11 compression from Velocity.
[16:38:35 INFO]: Paper: Using Java cipher from Velocity.
[16:38:35 INFO]: Preparing level "world"
[16:38:46 INFO]: Preparing start region for dimension minecraft:overworld
[16:38:46 INFO]: Preparing spawn area: 0%
[16:38:46 INFO]: Preparing spawn area: 0%
[16:38:46 INFO]: Time elapsed: 664 ms
[16:38:46 INFO]: Preparing start region for dimension minecraft:the_nether
[16:38:47 INFO]: Time elapsed: 181 ms
[16:38:47 INFO]: Preparing start region for dimension minecraft:the_end
[16:38:47 INFO]: Time elapsed: 240 ms
[16:38:47 INFO]: Running delayed init tasks
[16:38:47 INFO]: Done (12.532s)! For help, type "help"
[16:38:47 INFO]: Timings Reset
[16:38:47 INFO]: Stopping the server
[16:38:47 INFO]: Stopping server
[16:38:47 INFO]: Saving players
[16:38:47 INFO]: Saving worlds
[16:38:47 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[16:39:25 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[16:39:43 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[16:39:45 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[16:39:45 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[16:39:45 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[16:39:45 INFO]: ThreadedAnvilChunkStorage: All dimensions are saved
[16:39:46 INFO]: Flushing Chunk IO
[16:39:46 INFO]: Closing Thread Pool
2021-12-15 16:39:46,180 Log4j2-AsyncAppenderEventDispatcher-1-Async WARN Advanced terminal features are not available in this environment
[16:39:46 INFO]: Closing Server

 16:39:53  shane@Shanes-iMac  ~/a/z 
$ tou

 16:40:11  shane@Shanes-iMac  ~/a/z 
$  echo stop > testfile

 16:40:17  shane@Shanes-iMac  ~/a/z 
$ java -jar paper-1.18.1-76.jar < testfile
Starting org.bukkit.craftbukkit.Main
System Info: Java 17 (OpenJDK 64-Bit Server VM 17.0.1+12) Host: Mac OS X 10.16 (x86_64)
Loading libraries, please wait...
2021-12-15 16:40:23,062 ServerMain WARN Advanced terminal features are not available in this environment
[16:40:28 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
[16:40:29 INFO]: Reloading ResourceManager: Default, bukkit
[16:40:30 INFO]: Loaded 7 recipes
[16:40:32 INFO]: Starting minecraft server version 1.18.1
[16:40:32 INFO]: Loading properties
[16:40:32 INFO]: This server is running Paper version git-Paper-76 (MC: 1.18.1) (Implementing API version 1.18.1-R0.1-SNAPSHOT) (Git: 95d881f)
[16:40:33 INFO]: Server Ping Player Sample Count: 12
[16:40:33 INFO]: Using 4 threads for Netty based IO
[16:40:33 INFO]: Default game type: SURVIVAL
[16:40:33 INFO]: Generating keypair
[16:40:33 INFO]: Starting Minecraft server on *:25565
[16:40:33 INFO]: Using default channel type
[16:40:33 INFO]: Paper: Using Java 11 compression from Velocity.
[16:40:33 INFO]: Paper: Using Java cipher from Velocity.
[16:40:33 INFO]: Server permissions file permissions.yml is empty, ignoring it
[16:40:33 INFO]: Preparing level "world"
[16:40:34 INFO]: Preparing start region for dimension minecraft:overworld
[16:40:35 INFO]: Preparing spawn area: 0%
[16:40:35 INFO]: Time elapsed: 432 ms
[16:40:35 INFO]: Preparing start region for dimension minecraft:the_nether
[16:40:35 INFO]: Time elapsed: 226 ms
[16:40:35 INFO]: Preparing start region for dimension minecraft:the_end
[16:40:35 INFO]: Time elapsed: 257 ms
[16:40:35 INFO]: Running delayed init tasks
[16:40:35 INFO]: Done (3.146s)! For help, type "help"
[16:40:35 INFO]: Timings Reset
[16:40:36 INFO]: Stopping the server
[16:40:36 INFO]: Stopping server
[16:40:36 INFO]: Saving players
[16:40:36 INFO]: Saving worlds
[16:40:36 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[16:40:56 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
[16:41:04 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
[16:41:06 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
[16:41:06 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[16:41:06 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[16:41:06 INFO]: ThreadedAnvilChunkStorage: All dimensions are saved
[16:41:07 INFO]: Flushing Chunk IO
[16:41:07 INFO]: Closing Thread Pool
2021-12-15 16:41:07,017 Log4j2-AsyncAppenderEventDispatcher-1-Async WARN Advanced terminal features are not available in this environment
[16:41:07 INFO]: Closing Server

Cannot reproduce

Simonesien commented 2 years ago

That wonders me! I have no idea why it's working for you. It doesn't come from performance, my Server doesn't shut down even after 20 min. But I wonder why the error ServerMain WARN Advanced terminal features are not available in this environment at the beginning comes at all! Maybe I would see what I've done incorrectly if I did know it.

electronicboy commented 2 years ago

That error is because of the lack of a "real" console when you're piping input and is 100% expected in this case

There is a weird deadlock which I thought I hit with how long it started to take to shut down, if it sticks on the saving stuff could be that, otherwise, er... I'd be interested to see what you're seeing

Simonesien commented 2 years ago 
pi@minepi:~/minecraft-server/_____test $ ls -al
total 12
drwxr-xr-x  2 pi pi 4096 Dec 15 18:02 .
drwxr-xr-x 21 pi pi 4096 Dec 15 18:02 ..
-rw-r--r--  1 pi pi   10 Dec 15 18:02 eula.txt
lrwxrwxrwx  1 pi pi   42 Dec 15 18:02 server.jar -> /home/pi/minecraft-server/1.18.1-paper.jar
-rw-r--r--  1 pi pi    0 Dec 15 18:02 server.properties
pi@minepi:~/minecraft-server/_____test $ cat eula.txt 
eula=true
pi@minepi:~/minecraft-server/_____test $ cat server.properties 
pi@minepi:~/minecraft-server/_____test $ echo "stop" | java -jar server.jar nogui
Downloading mojang_1.18.1.jar
Applying patches
Starting org.bukkit.craftbukkit.Main
System Info: Java 17 (Java HotSpot(TM) 64-Bit Server VM 17.0.1+12-LTS-39) Host: Linux 5.10.63-v8+ (aarch64)
Loading libraries, please wait...
2021-12-15 18:03:27,261 ServerMain WARN Advanced terminal features are not available in this environment
[18:03:45 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
[18:03:45 INFO]: Found new data pack file/bukkit, loading it automatically
[18:03:46 INFO]: Reloading ResourceManager: Default, bukkit
[18:03:50 INFO]: Loaded 7 recipes
[18:03:57 INFO]: Starting minecraft server version 1.18.1
[18:03:57 INFO]: Loading properties
[18:03:57 INFO]: This server is running Paper version git-Paper-68 (MC: 1.18.1) (Implementing API version 1.18.1-R0.1-SNAPSHOT) (Git: 1c779c2)
[18:03:57 INFO]: Server Ping Player Sample Count: 12
[18:03:57 INFO]: Using 4 threads for Netty based IO
[18:03:58 INFO]: Default game type: SURVIVAL
[18:03:58 INFO]: Generating keypair
[18:03:58 INFO]: Starting Minecraft server on *:25565
[18:03:58 INFO]: Using epoll channel type
[18:03:58 INFO]: Paper: Using libdeflate (Linux aarch64) compression from Velocity.
[18:03:58 INFO]: Paper: Using OpenSSL (Linux aarch64) cipher from Velocity.
[18:03:59 INFO]: Preparing level "world"
[18:04:30 INFO]: Preparing start region for dimension minecraft:overworld
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:32 INFO]: Preparing spawn area: 0%
[18:04:33 INFO]: Time elapsed: 2887 ms
[18:04:33 INFO]: Preparing start region for dimension minecraft:the_nether
[18:04:34 INFO]: Time elapsed: 1502 ms
[18:04:34 INFO]: Preparing start region for dimension minecraft:the_end
[18:04:35 INFO]: Time elapsed: 1286 ms
[18:04:36 INFO]: Running delayed init tasks
[18:04:36 INFO]: Done (38.651s)! For help, type "help"
[18:04:36 INFO]: Timings Reset
[18:04:36 INFO]: Stopping the server
[18:04:37 ERROR]: ------------------------------
[18:04:37 ERROR]: The server has stopped responding! This is (probably) not a Paper bug.
[18:04:37 ERROR]: If you see a plugin in the Server thread dump below, then please report it to that author
[18:04:37 ERROR]:    *Especially* if it looks like HTTP or MySQL operations are occurring
[18:04:37 ERROR]: If you see a world save or edit, then it means you did far more than your server can handle at once
[18:04:37 ERROR]:    If this is the case, consider increasing timeout-time in spigot.yml but note that this will replace the crash with LARGE lag spikes
[18:04:37 ERROR]: If you are unsure or still think this is a Paper bug, please report this to https://github.com/PaperMC/Paper/issues
[18:04:37 ERROR]: Be sure to include ALL relevant console errors and Minecraft crash reports
[18:04:37 ERROR]: Paper version: git-Paper-68 (MC: 1.18.1)
[18:04:37 ERROR]: ------------------------------
[18:04:37 ERROR]: Server thread dump (Look for plugins here before reporting to Paper!):
[18:04:37 ERROR]: ------------------------------
[18:04:37 ERROR]: Current Thread: Server thread
[18:04:37 ERROR]:   PID: 24 | Suspended: false | Native: false | State: RUNNABLE
[18:04:37 ERROR]:   Stack:
[18:04:37 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.defineClass1(Native Method)
[18:04:37 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.defineClass(ClassLoader.java:1012)
[18:04:37 ERROR]:       java.base@17.0.1/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
[18:04:37 ERROR]:       java.base@17.0.1/java.net.URLClassLoader.defineClass(URLClassLoader.java:524)
[18:04:37 ERROR]:       java.base@17.0.1/java.net.URLClassLoader$1.run(URLClassLoader.java:427)
[18:04:37 ERROR]:       java.base@17.0.1/java.net.URLClassLoader$1.run(URLClassLoader.java:421)
[18:04:37 ERROR]:       java.base@17.0.1/java.security.AccessController.executePrivileged(AccessController.java:807)
[18:04:37 ERROR]:       java.base@17.0.1/java.security.AccessController.doPrivileged(AccessController.java:712)
[18:04:37 ERROR]:       java.base@17.0.1/java.net.URLClassLoader.findClass(URLClassLoader.java:420)
[18:04:37 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.loadClass(ClassLoader.java:587)
[18:04:37 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.loadClass(ClassLoader.java:520)
[18:04:37 ERROR]:       org.bukkit.entity.EntityType.<clinit>(EntityType.java:260)
[18:04:37 ERROR]:       org.bukkit.craftbukkit.v1_18_R1.util.CraftMagicNumbers.<clinit>(CraftMagicNumbers.java:123)
[18:04:37 ERROR]:       org.bukkit.craftbukkit.v1_18_R1.CraftServer.getUnsafe(CraftServer.java:2598)
[18:04:37 ERROR]:       org.bukkit.Bukkit.getUnsafe(Bukkit.java:2021)
[18:04:37 ERROR]:       co.aikar.timings.FullServerTickHandler.stopTiming(FullServerTickHandler.java:79)
[18:04:37 ERROR]:       net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1542)
[18:04:37 ERROR]:       net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1264)
[18:04:37 ERROR]:       net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:317)
[18:04:37 ERROR]:       net.minecraft.server.MinecraftServer$$Lambda$3952/0x00000008014c6b70.run(Unknown Source)
[18:04:37 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:37 ERROR]: ------------------------------
[18:04:37 ERROR]: Entire Thread Dump:
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Reference Handler
[18:04:38 ERROR]:   PID: 2 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.Reference.waitForReferencePendingList(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.Reference.processPendingReferences(Reference.java:253)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.Reference$ReferenceHandler.run(Reference.java:215)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Finalizer
[18:04:38 ERROR]:   PID: 3 | Suspended: false | Native: false | State: WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Object.wait(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:172)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Signal Dispatcher
[18:04:38 ERROR]:   PID: 4 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Notification Thread
[18:04:38 ERROR]:   PID: 11 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Common-Cleaner
[18:04:38 ERROR]:   PID: 12 | Suspended: false | Native: false | State: TIMED_WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Object.wait(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:162)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: DestroyJavaVM
[18:04:38 ERROR]:   PID: 16 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Log4j2-AsyncAppenderEventDispatcher-1-Async
[18:04:38 ERROR]:   PID: 20 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.util.GregorianCalendar.computeFields(GregorianCalendar.java:2297)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.GregorianCalendar.computeFields(GregorianCalendar.java:2273)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.Calendar.setTimeInMillis(Calendar.java:1827)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.Calendar$Builder.build(Calendar.java:1515)
[18:04:38 ERROR]:       java.base@17.0.1/sun.util.locale.provider.CalendarProviderImpl.getInstance(CalendarProviderImpl.java:87)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.Calendar.createCalendar(Calendar.java:1692)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.Calendar.getInstance(Calendar.java:1671)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.util.datetime.FastDatePrinter.newCalendar(FastDatePrinter.java:467)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.util.datetime.FastDatePrinter.format(FastDatePrinter.java:493)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.util.datetime.FastDateFormat.format(FastDateFormat.java:467)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.DatePatternConverter$PatternFormatter.formatToBuffer(DatePatternConverter.java:76)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.DatePatternConverter.formatWithoutAllocation(DatePatternConverter.java:295)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.DatePatternConverter.format(DatePatternConverter.java:288)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.DatePatternConverter.format(DatePatternConverter.java:265)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:44)
[18:04:38 ERROR]:       net.minecrell.terminalconsole.HighlightErrorConverter.format(HighlightErrorConverter.java:93)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:44)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.layout.PatternLayout$PatternSelectorSerializer.toSerializable(PatternLayout.java:561)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.layout.PatternLayout$PatternSelectorSerializer.toSerializable(PatternLayout.java:552)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:217)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:60)
[18:04:38 ERROR]:       net.minecrell.terminalconsole.TerminalConsoleAppender.append(TerminalConsoleAppender.java:256)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:84)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:84)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.dispatch(AsyncAppenderEventDispatcher.java:119)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.dispatchAll(AsyncAppenderEventDispatcher.java:81)
[18:04:38 ERROR]:       org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.run(AsyncAppenderEventDispatcher.java:63)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Timer hack thread
[18:04:38 ERROR]:   PID: 22 | Suspended: false | Native: false | State: TIMED_WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.sleep(Native Method)
[18:04:38 ERROR]:       net.minecraft.Util$6.run(Util.java:668)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Worker-Main-1
[18:04:38 ERROR]:   PID: 23 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.synth.PerlinNoise.getValue(PerlinNoise.java:153)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.synth.PerlinNoise.getValue(PerlinNoise.java:141)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.synth.NormalNoise.getValue(NormalNoise.java:87)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseSampler.getOffset(NoiseSampler.java:590)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseSampler.noiseData(NoiseSampler.java:538)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseChunk.computePreliminarySurfaceLevel(NoiseChunk.java:133)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseChunk$$Lambda$4232/0x0000000801662ab0.get(Unknown Source)
[18:04:38 ERROR]:       it.unimi.dsi.fastutil.longs.Long2IntOpenHashMap.computeIfAbsent(Long2IntOpenHashMap.java:543)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseChunk.preliminarySurfaceLevel(NoiseChunk.java:118)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.Aquifer$NoiseBasedAquifer.computeFluid(Aquifer.java:507)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.Aquifer$NoiseBasedAquifer.getAquiferStatus(Aquifer.java:482)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.Aquifer$NoiseBasedAquifer.computeSubstance(Aquifer.java:285)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseSampler.lambda$makeBaseNoiseFiller$10(NoiseSampler.java:451)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseSampler$$Lambda$4224/0x0000000801661530.calculate(Unknown Source)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseChunk.updateNoiseAndGenerateBaseState(NoiseChunk.java:181)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.ChunkGeneratorAbstract$$Lambda$4069/0x00000008015c53c0.apply(Unknown Source)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.material.MaterialRuleList.apply(MaterialRuleList.java:20)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseBasedChunkGenerator.iterateNoiseColumn(NoiseBasedChunkGenerator.java:213)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.NoiseBasedChunkGenerator.getBaseColumn(NoiseBasedChunkGenerator.java:181)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.structure.NetherFossilFeature.pieceGeneratorSupplier(NetherFossilFeature.java:40)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.structure.WorldGenFeatureNetherFossil$$Lambda$1952/0x0000000801227958.createGenerator(Unknown Source)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.feature.StructureFeature.generate(StructureFeature.java:234)
[18:04:38 ERROR]:       net.minecraft.world.level.levelgen.feature.ConfiguredStructureFeature.generate(ConfiguredStructureFeature.java:36)
[18:04:38 ERROR]:       net.minecraft.world.level.chunk.ChunkGenerator.createStructures(ChunkGenerator.java:492)
[18:04:38 ERROR]:       net.minecraft.world.level.chunk.ChunkStatus.lambda$static$2(ChunkStatus.java:51)
[18:04:38 ERROR]:       net.minecraft.world.level.chunk.ChunkStatus$$Lambda$2422/0x00000008012c32a0.doWork(Unknown Source)
[18:04:38 ERROR]:       net.minecraft.world.level.chunk.ChunkStatus.generate(ChunkStatus.java:273)
[18:04:38 ERROR]:       net.minecraft.server.level.ChunkMap.lambda$scheduleChunkGeneration$35(ChunkMap.java:1211)
[18:04:38 ERROR]:       net.minecraft.server.level.PlayerChunkMap$$Lambda$4213/0x000000080165e8e8.apply(Unknown Source)
[18:04:38 ERROR]:       com.mojang.datafixers.util.Either$Left.map(Either.java:38)
[18:04:38 ERROR]:       net.minecraft.server.level.ChunkMap.lambda$scheduleChunkGeneration$37(ChunkMap.java:1209)
[18:04:38 ERROR]:       net.minecraft.server.level.PlayerChunkMap$$Lambda$4198/0x000000080165a4e8.apply(Unknown Source)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482)
[18:04:38 ERROR]:       net.minecraft.server.level.ChunkTaskPriorityQueueSorter.lambda$message$1(ChunkTaskPriorityQueueSorter.java:58)
[18:04:38 ERROR]:       net.minecraft.server.level.ChunkTaskQueueSorter$$Lambda$4211/0x000000080165e488.run(Unknown Source)
[18:04:38 ERROR]:       net.minecraft.util.thread.ProcessorMailbox.pollTask(ProcessorMailbox.java:91)
[18:04:38 ERROR]:       net.minecraft.util.thread.ProcessorMailbox.pollUntil(ProcessorMailbox.java:146)
[18:04:38 ERROR]:       net.minecraft.util.thread.ProcessorMailbox.run(ProcessorMailbox.java:102)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Server thread
[18:04:38 ERROR]:   PID: 24 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Thread is waiting on monitor(s):
[18:04:38 ERROR]:       Locked on:java.base@17.0.1/java.lang.ClassLoader.loadClass(ClassLoader.java:587)
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.defineClass1(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.defineClass(ClassLoader.java:1012)
[18:04:38 ERROR]:       java.base@17.0.1/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
[18:04:38 ERROR]:       java.base@17.0.1/java.net.URLClassLoader.defineClass(URLClassLoader.java:524)
[18:04:38 ERROR]:       java.base@17.0.1/java.net.URLClassLoader$1.run(URLClassLoader.java:427)
[18:04:38 ERROR]:       java.base@17.0.1/java.net.URLClassLoader$1.run(URLClassLoader.java:421)
[18:04:38 ERROR]:       java.base@17.0.1/java.security.AccessController.executePrivileged(AccessController.java:807)
[18:04:38 ERROR]:       java.base@17.0.1/java.security.AccessController.doPrivileged(AccessController.java:712)
[18:04:38 ERROR]:       java.base@17.0.1/java.net.URLClassLoader.findClass(URLClassLoader.java:420)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.loadClass(ClassLoader.java:587)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.ClassLoader.loadClass(ClassLoader.java:520)
[18:04:38 ERROR]:       org.bukkit.entity.EntityType.<clinit>(EntityType.java:269)
[18:04:38 ERROR]:       org.bukkit.craftbukkit.v1_18_R1.util.CraftMagicNumbers.<clinit>(CraftMagicNumbers.java:123)
[18:04:38 ERROR]:       org.bukkit.craftbukkit.v1_18_R1.CraftServer.getUnsafe(CraftServer.java:2598)
[18:04:38 ERROR]:       org.bukkit.Bukkit.getUnsafe(Bukkit.java:2021)
[18:04:38 ERROR]:       co.aikar.timings.FullServerTickHandler.stopTiming(FullServerTickHandler.java:79)
[18:04:38 ERROR]:       net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1542)
[18:04:38 ERROR]:       net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1264)
[18:04:38 ERROR]:       net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:317)
[18:04:38 ERROR]:       net.minecraft.server.MinecraftServer$$Lambda$3952/0x00000008014c6b70.run(Unknown Source)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Paper Async Chunk Task Thread #0
[18:04:38 ERROR]:   PID: 31 | Suspended: false | Native: false | State: WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
[18:04:38 ERROR]:       com.destroystokyo.paper.io.QueueExecutorThread.run(QueueExecutorThread.java:84)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Paper Async Chunk Urgent Task Thread
[18:04:38 ERROR]:   PID: 32 | Suspended: false | Native: false | State: WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
[18:04:38 ERROR]:       com.destroystokyo.paper.io.QueueExecutorThread.run(QueueExecutorThread.java:84)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Paper Watchdog Thread
[18:04:38 ERROR]:   PID: 33 | Suspended: false | Native: false | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.management@17.0.1/sun.management.ThreadImpl.dumpThreads0(Native Method)
[18:04:38 ERROR]:       java.management@17.0.1/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:521)
[18:04:38 ERROR]:       java.management@17.0.1/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:509)
[18:04:38 ERROR]:       org.spigotmc.WatchdogThread.run(WatchdogThread.java:204)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: pool-4-thread-1
[18:04:38 ERROR]:   PID: 34 | Suspended: false | Native: false | State: TIMED_WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1672)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1062)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1122)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Netty Epoll Server IO #0
[18:04:38 ERROR]:   PID: 37 | Suspended: false | Native: true | State: RUNNABLE
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       io.netty.channel.epoll.Native.epollWait(Native Method)
[18:04:38 ERROR]:       io.netty.channel.epoll.Native.epollWait(Native.java:192)
[18:04:38 ERROR]:       io.netty.channel.epoll.Native.epollWait(Native.java:185)
[18:04:38 ERROR]:       io.netty.channel.epoll.EpollEventLoop.epollWaitNoTimerChange(EpollEventLoop.java:290)
[18:04:38 ERROR]:       io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:347)
[18:04:38 ERROR]:       io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
[18:04:38 ERROR]:       io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Paper RegionFile IO Thread
[18:04:38 ERROR]:   PID: 38 | Suspended: false | Native: false | State: WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
[18:04:38 ERROR]:       com.destroystokyo.paper.io.QueueExecutorThread.run(QueueExecutorThread.java:84)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: IO-Worker-1
[18:04:38 ERROR]:   PID: 39 | Suspended: false | Native: false | State: TIMED_WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:401)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:903)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1061)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1122)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: IO-Worker-2
[18:04:38 ERROR]:   PID: 40 | Suspended: false | Native: false | State: TIMED_WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:401)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:903)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1061)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1122)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:38 ERROR]: Current Thread: Craft Async Scheduler Management Thread
[18:04:38 ERROR]:   PID: 41 | Suspended: false | Native: false | State: WAITING
[18:04:38 ERROR]:   Stack:
[18:04:38 ERROR]:       java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:341)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3463)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3434)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1623)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:435)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1062)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1122)
[18:04:38 ERROR]:       java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[18:04:38 ERROR]:       java.base@17.0.1/java.lang.Thread.run(Thread.java:833)
[18:04:38 ERROR]: ------------------------------
[18:04:39 INFO]: Stopping main thread (Ignore any thread death message you see! - DO NOT REPORT THREAD DEATH TO PAPER)

Exception: java.lang.ThreadDeath thrown from the UncaughtExceptionHandler in thread "Server thread"
[18:04:39 INFO]: Stopping server
[18:04:39 INFO]: Saving players
[18:04:39 INFO]: Saving worlds
[18:04:39 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld

Even after 6 Minutes, there comes nothing more.

MiniDigger commented 2 years ago

isn't the real solution here to add a cli arg that stops the server after the spawn has been generated? I thought we had something like this, but I think I am confusing it with the arg in paperclip

e-im commented 2 years ago

An init command was discussed in #5459 and #5046. While this could be done for configs themselves, it feels a bit unnecessary as the method in this issue should work. If you want plugins as well, you'd effectively be doing the exact same thing as here.

This generally seems like some weird environment issue and out of paper's control.

If an arg is the desired solution, one of the above issues can be reopened.