Server hangs on closing
Jeffrey2911 opened this issue · 35 comments
When using the stop command to close the server, the server hangs on
Sending config unload event for refurbished_furniture.server.toml
full log --> https://mclo.gs/xiTM8W0
I'm having a similar issue on my two servers with furniture mod installed.
Minecraft version 1.20.1, Fabric version 0.16.3 and mod version 1.0.6.
No configapi installed.
[10:39:44] [Server thread/INFO]: Unloading server configs...
[10:39:44] [Server thread/INFO]: Sending config unload event for refurbished_furniture.server.toml
[10:39:44] [pool-2-thread-1/INFO]: Reloaded: 'yawp-common.toml'
[10:39:44] [pool-2-thread-1/INFO]: Reloaded: 'yawp-flags.toml'
[10:39:44] [pool-2-thread-1/INFO]: Reloaded: 'yawp-region-defaults.toml'
I doubt it's yawp and suspect refurbished_furniture.server.toml.
Sometimes the server is hanging for just a minute, another time my server was stuck on unload event for the rest of the night until I eventually killed it. This behavior makes restarting the server difficult and risky.
I doubt it's anything to do with the unload event since that doesn't block any game threads or withhold resources. At the moment, I have no method to reproduce the issue so this makes this quite difficult. I could offer a custom version of Framework that includes additional logging.
Okay, I've created a custom version with a potential fix and extra logging. It can be downloaded from here:
https://github.com/MrCrayfish/Framework/actions/runs/10764776778
You can see all the changes I made here.
MrCrayfish/Framework@multiloader/1.20.X...multiloader/1.20.X-debug
Yeah, the clearest sign is the line [11:10:10] [Server thread/INFO]: Closing config: ./config/refurbished_furniture.server.toml as this is when the resource is freed. So if the server was waiting for a resource to be released, it would have been that.
I believe Microsoft has a tool that you can use to see the files being used by a process.
https://learn.microsoft.com/en-us/sysinternals/downloads/process-explorer
You could also try dumping the Java threads, and this should show which ones are running/waiting.
https://www.baeldung.com/java-thread-dump
Checked the debug build you've provided.
Following the logs- it seems it's most likely not Framework's fault, since provided logs detected all logs to be unloaded successfully on my side:
[11:10:10] [Server thread/INFO]: Unloading server configs...
[11:10:10] [Server thread/INFO]: Unwatching config: ./config/refurbished_furniture.server.toml
[11:10:10] [Server thread/INFO]: Closing config: ./config/refurbished_furniture.server.toml
[11:10:10] [Server thread/INFO]: Sending config unload event for refurbished_furniture.server.toml
[11:10:10] [Server thread/INFO]: Checking if all Framework configs unloaded...
[11:10:10] [Server thread/INFO]: Is 'refurbished_furniture.server.toml' unloaded: true
[11:10:10] [Server thread/INFO]: Is 'refurbished_furniture.client.toml' unloaded: true
[11:10:11] [pool-2-thread-1/INFO]: Reloaded: 'yawp-common.toml'
[11:10:11] [pool-2-thread-1/INFO]: Reloaded: 'yawp-flags.toml'
[11:10:11] [pool-2-thread-1/INFO]: Reloaded: 'yawp-region-defaults.toml'
I'll do my own testing with YAWP disabled, but for now I have no reason to believe this behavior is caused by Framework.
EDIT: Even without YAWP, the server still hangs up on the shutdown, I don't know anymore...
EDIT 2: Disabled all YAWP, Framework and Refurbished Furnitures and the issue still occured. It must lay somewhere deeper in my case then, but I do not suspect Framework anymore 🙂
I am seeing this bug in version 1.21.1 running on Ubuntu.. I noticed your patch is on the 1.20.X branch, will this be patched on for 1.21.1 too? Is there anything we can do to fix it before the patch is released?
@olicooper As shown in the discussion already, I do not know the exact cause and have only made a guess. The patch that I included recently was to potentially fix the issue, but I wasn't able to confirm if it fixed the issue since I haven't been able to reproduce it yet. However @Sevelar's second edit indicates they encountered the problem without my mods installed.
Can you provide more details about your game? Are you running a server, what OS and version, mods versions, etc. Logs too will help. (Use https://mclo.gs)
Same issue on my server (forge47.3.7, MC version 1.20.1, mod version 1.0.6)
The server will get stuck while shutting down
@JIAFALSEDREAM What OS?
@JIAFALSEDREAM What OS?
winserver2016
OS is Ubuntu 24.04.1 running headless java (openjdk-21-jdk-headless) and systemd to start the minecraft server with /bin/sh -c "./run.sh --nogui"... Initially set the server up with unmodded MC which worked perfectly, then I noticed this when shutting the process down. I issue the /stop command to shut MC down.
$java -version
openjdk version "21.0.4" 2024-07-16
OpenJDK Runtime Environment (build 21.0.4+7-Ubuntu-1ubuntu224.04)
OpenJDK 64-Bit Server VM (build 21.0.4+7-Ubuntu-1ubuntu224.04, mixed mode, sharing)
run.sh
java -jar forge-1.21.1-52.0.15-shim.jar --onlyCheckJava || exit 1
java @user_jvm_args.txt @libraries/net/minecraftforge/forge/1.21.1-52.0.15/unix_args.txt "$@"user_jvm_args.txt
-Xms1.5G
-Xmx2G
-XX:+UnlockExperimentalVMOptions
-XX:+UseZGC
latest.log
[cpw.mods.modlauncher.Launcher/MODLAUNCHER]: ModLauncher running: args [--launchTarget, forge_server, --nogui]
[cpw.mods.modlauncher.Launcher/MODLAUNCHER]: JVM identified as Ubuntu OpenJDK 64-Bit Server VM 21.0.4+7-Ubuntu-1ubuntu224.04
[cpw.mods.modlauncher.Launcher/MODLAUNCHER]: ModLauncher 10.2.1 starting: java version 21.0.4 by Ubuntu; OS Linux arch amd64 version 6.8.12-2
[net.minecraftforge.fml.loading.ImmediateWindowHandler/]: ImmediateWindowProvider not loading because launch target is forge_server
[mixin/]: SpongePowered MIXIN Subsystem Version=0.8.7 Source=jar:file:///[redacted]/libraries/org/spongepowered/mixin/0.8.7/mixin-0.8.7.jar!/ Service=ModLauncher Env=SERVER
[net.minecraftforge.common.ForgeMod/FORGEMOD]: Forge mod loading, version 52.0.15, for MC 1.21.1 with MCP 20240808.132146
[net.minecraftforge.common.MinecraftForge/FORGE]: MinecraftForge v52.0.15 Initialized
...
[net.minecraft.server.MinecraftServer/]: Stopping the server
[net.minecraft.server.MinecraftServer/]: Stopping server
[net.minecraft.server.MinecraftServer/]: Saving players
[net.minecraft.server.MinecraftServer/]: Saving worlds
[net.minecraft.server.MinecraftServer/]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[net.minecraft.server.MinecraftServer/]: Saving chunks for level 'ServerLevel[world]'/minecraft:the_end
[net.minecraft.server.MinecraftServer/]: Saving chunks for level 'ServerLevel[world]'/minecraft:the_nether
[net.minecraft.server.MinecraftServer/]: ThreadedAnvilChunkStorage (world): All chunks are saved
[net.minecraft.server.MinecraftServer/]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
[net.minecraft.server.MinecraftServer/]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
[net.minecraft.server.MinecraftServer/]: ThreadedAnvilChunkStorage: All dimensions are saved
[Framework/]: Unloading server configs...
[Framework/]: Sending config unload event for refurbished_furniture.server.toml
$ls mods/
'Storage Drawers-forge-1.21-13.5.0.jar' Xaeros_Minimap_24.4.0_Forge_1.21.jar framework-forge-1.21.1-0.9.2.jar refurbished_furniture-forge-1.21.1-1.0.6.jar travelersbackpack-forge-1.21-10.0.1.jar
StorageDrawers-1.21-Forge-13.2.1.jar balm-forge-1.21.1-21.0.19-all.jar grindenc-forge-1.21.x-v2.2.jar smallships-forge-1.21.1-2.0.0-b1.5.jar waystones-forge-1.21.1-21.1.3.jar
XaerosWorldMap_1.39.0_Forge_1.21.jar 'dungeons-and-taverns-v4.4.4 [Forge].jar' jei-1.21.1-forge-19.8.4.113.jar trashslot-forge-1.21.1-21.1.1.jar waystones-forge-1.21.1-21.1.4.jar
Thanks for the detailed information @olicooper.
I have successfully managed to reproduce the issue on Windows, however it's not consistent. Sometimes it happens, sometimes it doesn't. This leads me to believe there is a race condition. The threads that watch config files for changes (hot reloading) are not being shutdown correctly. While this issue has been reported to be caused by my mod, I have been able to produce the same issue on Forge with 0 mods installed.
I can confirm the issue happens on Forge, however I am unable to get it to occur on Fabric/NeoForge. @Sevelar Do you have any new revelations about your problem since you experienced it on Fabric without Framework/Furniture mod? Any chance you could also provide a list of all the mods you had installed?
i am also getting the same problem with the server getting stuck, i'm hosting an ATM10 server on the version 1.7 of the modpack, the problem seems to be also occurring with NeoForge.
@felipextz Thanks for the info. I have just confirmed the problem is replicable on NeoForge with 0 mods installed. Issue seems to be deeper.
So the common denominator in all this has been a library called NightConfig. Forge/NeoForge use this, and Framework uses this (only on Fabric). The issue is a non-daemon thread not terminating on shutdown. Sometimes it terminates, sometimes it doesn't. Seems to be a race condition on Forge. NeoForge I was able to replicate 100%. I am now able to look into a fix for Framework, and I will be submitting a report to Forge/NeoForge.
@JIAFALSEDREAM I can't seem to produce the issue I found on 1.20.1, can you send your full mod list and debug log? (Use https://mclo.gs to send logs)
@JIAFALSEDREAM Any chance you can send the shutdown sequence of the debug log? The sent log was cut off. Also how often does the issue occur?
This may be a little advanced, but can you capture a thread dump? Basically you'll need to encounter the issue again, when that happens, dump the threads. Since you're using Windows, you should be able to press Ctrl + Shift + Pause in the same CMD window that the server is running.
Just performed a test myself with MemorySweep and it hung the server on close every time. As soon as I removed the mod and ran stop, server closed fine.
@JIAFALSEDREAM Any chance you can send the shutdown sequence of the debug log? The sent log was cut off. Also how often does the issue occur?
This may be a little advanced, but can you capture a thread dump? Basically you'll need to encounter the issue again, when that happens, dump the threads. Since you're using Windows, you should be able to press Ctrl + Shift + Pause in the same CMD window that the server is running.
Almost 99% of the time when the server is down (including the end of the shutdown with the ctrl+c or other crashes). Then there's the question about Capture a Thread Dump, hopefully this is the https://mclo.gs/FBQ0H11 you need
and debug log https://mclo.gs/I516f2V
@JIAFALSEDREAM Thanks for the thread dump. After analyzing it, it seems there is a thread holding it up but is not related to the config watcher thread issue I discovered earlier.
Specifically this thread:
"Timer-1" #110 [148] prio=5 os_prio=0 cpu=0.00ms elapsed=44.66s tid=0x0000024d484a5aa0 nid=148 in Object.wait() [0x000000ab007ff000]
--
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait0([email protected]/Native Method)
- waiting on <0x00000005bc0008b0> (a java.util.TaskQueue)
at java.lang.Object.wait([email protected]/Object.java:366)
at java.lang.Object.wait([email protected]/Object.java:339)
at java.util.TimerThread.mainLoop([email protected]/Timer.java:537)
- locked <0x00000005bc0008b0> (a java.util.TaskQueue)
at java.util.TimerThread.run([email protected]/Timer.java:516)
"Timer-1" is a non-daemon type (this means the programmer must manually close it to complete the shutdown. Compared to an actual daemon thread, which will be terminated automatically on shutdown). This can be identified as the word daemon is missing before the text prio=5.
I can only guess that another mod is running some sort of timing, like running code at a fixed interval. Minecraft does use Timers in it's own game for showing regional compliances (like South Korea, they show a notification toast in game for how many hours you have played in your current session) but they are safely shutdown. I will try and go through you mod list and find suspecting mods.
@JIAFALSEDREAM Try removing MemorySweep and test again. I found a similar issue where the server would not close. You'll need to translate it. Tki-sor/MemorySweep#4
Just performed a test myself with MemorySweep and it hung the server on close every time. As soon as I removed the mod and ran
stop, server closed fine.
Due to time constraints, I will try the day after tomorrow. Thank you for your help
Just performed a test myself with MemorySweep and it hung the server on close every time. As soon as I removed the mod and ran
stop, server closed fine.
Done! no problem, thank you again for your help😃, and do I need to close this issue?
Done! no problem, thank you again for your help😃, and do I need to close this issue?
Unfortunately the issue is not completely resolved yet. Your issue was different to the one regarding the NightConfig library.
It doesn't seem to be completely resolved, and recently this problem has resurfaced. the thread dump: https://mclo.gs/iUTQ3AF
It doesn't seem to be completely resolved, and recently this problem has resurfaced. the thread dump: https://mclo.gs/iUTQ3AF
According to the logs, it's waiting to dispose the server GUI window. Try running your server with --nogui
Not sure what the context of that dump is. Looks like the server failed to start. Did you add the argument correctly?
My server can start up normally, and I am currently migrating my server to a new service provider and will be using Ubuntu system
It doesn't seem to be completely resolved, and recently this problem has resurfaced. the thread dump: https://mclo.gs/iUTQ3AF
According to the logs, it's waiting to dispose the server GUI window. Try running your server with
--nogui
Not sure what the context of that dump is. Looks like the server failed to start. Did you add the argument correctly?
My server can start up normally, and I am currently migrating my server to a new service provider and will be using Ubuntu system
What is the context of the thread dump? Because it's showing significantly less threads than before.
@MrCrayfish This is resolved for me on NeoForge with Framework 1.21.1-0.9.4 and Furniture 1.21.1-1.0.8 on a large pack I was having issue on. I've been following this issue, but updated today and tested on our server. The new filewatcher in Framework is working well.