[SPIGOT-6956] setKeepSpawnInMemory(false) works great, but causes shutdowndown to hang Created: 02/Mar/22 Updated: 25/Dec/24 Resolved: 05/Mar/22 |
|
Status: | Resolved |
Project: | Spigot |
Component/s: | None |
Affects Version/s: | None |
Fix Version/s: | None |
Type: | Bug | Priority: | Minor |
Reporter: | gizmo | Assignee: | Unassigned |
Resolution: | Fixed | Votes: | 1 |
Labels: | 1.18.2, chunk, crash, hang | ||
Environment: |
Windows 10 |
Attachments: |
![]() ![]() ![]() ![]() ![]() ![]() |
Version: | 3446-Spigot-fb0dd5f-6e75502 (MC: 1.18.2) (Implementing API version 1.18.2-R0.1-SNAPSHOT) |
Guidelines Read: | Yes |
Description |
when setKeepSpawnInMemory is set to false on a world it causes server shutdown to hang on saving worlds. Eventually this hang causes spigot to stop responding.
In order to reproduce this bug you must: 1: install the attached plugin on your server. (it's a minimal reproducer jar). 2: log in and alter the world. (break some blocks) 3: shutdown the server. (/stop command) provided attachments are the log and a minimal reproducer plugin jar.
I spent 1 hour ensuring that to the best of my ability this indeed appears to be a bug. This was not an issue in 1.18.1 from what i can tell. |
Comments |
Comment by Village_Admin [ 08/Mar/22 ] |
Also can confirm, so far no more hanging on shutdown. |
Comment by datatags [ 07/Mar/22 ] |
Looks like that fixed it, thank you!! |
Comment by md_5 [ 07/Mar/22 ] |
Sorry, pushed now |
Comment by md_5 [ 06/Mar/22 ] |
Oh strange, my commit didn't push. I will redo it this evening. |
Comment by datatags [ 06/Mar/22 ] |
Still locks up, but looks like a slightly different message: https://pastebin.com/DS5FR6UA Although the only change I see between 3450 and 3451 is "Improve consistency of Tag API," is that correct? |
Comment by md_5 [ 05/Mar/22 ] |
Please try the latest build as another fix (3451) |
Comment by datatags [ 04/Mar/22 ] |
That didn't fix it for me, thread dump: https://pastebin.com/JtD3zcGd |
Comment by md_5 [ 04/Mar/22 ] |
I have rewritten setKeepSpawnInMemory so more of the same code runs on both times. This may fix the issue (certainly its the only idea I have) |
Comment by Village_Admin [ 04/Mar/22 ] |
I am also having this issue. Server hangs on saving worlds until timeout error. This is on a linux server. Using newest buildtools, latest spigot version, and Java (openjdk 17.0.1 2021-10-19).
On my server, i have a plugin using setKeepSpawnInMemory(false).
Here is the error when it does hang if it gives any clue where to look... [19:22:04] [Server thread/INFO]: Stopping server [19:22:04] [Server thread/INFO]: Saving players [19:22:05] [Server thread/INFO]: Saving worlds [19:24:45] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:45] [Spigot Watchdog Thread/ERROR]: The server has stopped responding! This is (probably) not a Spigot bug. [19:24:45] [Spigot Watchdog Thread/ERROR]: If you see a plugin in the Server thread dump below, then please report it to that author [19:24:45] [Spigot Watchdog Thread/ERROR]: *Especially* if it looks like HTTP or MySQL operations are occurring [19:24:45] [Spigot Watchdog Thread/ERROR]: If you see a world save or edit, then it means you did far more than your server can handle at once [19:24:45] [Spigot Watchdog Thread/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 [19:24:45] [Spigot Watchdog Thread/ERROR]: If you are unsure or still think this is a Spigot bug, please report to https://www.spigotmc.org/ [19:24:45] [Spigot Watchdog Thread/ERROR]: Be sure to include ALL relevant console errors and Minecraft crash reports [19:24:45] [Spigot Watchdog Thread/ERROR]: Spigot version: 3449-Spigot-fb0dd5f-21fe78a (MC: 1.18.2) [19:24:45] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:45] [Spigot Watchdog Thread/ERROR]: Server thread dump (Look for plugins here before reporting to Spigot!): [19:24:45] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:45] [Spigot Watchdog Thread/ERROR]: Current Thread: Server thread [19:24:45] [Spigot Watchdog Thread/ERROR]: PID: 61 | Suspended: false | Native: false | State: TIMED_WAITING [19:24:45] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:45] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method) [19:24:45] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.util.thread.IAsyncTaskHandler.bp(SourceFile:152) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.util.thread.IAsyncTaskHandler.c(SourceFile:142) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.MinecraftServer.x(MinecraftServer.java:1152) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.MinecraftServer.t(MinecraftServer.java:946) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.dedicated.DedicatedServer.t(DedicatedServer.java:717) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.MinecraftServer.w(MinecraftServer.java:1092) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.MinecraftServer.lambda$0(MinecraftServer.java:306) [19:24:45] [Spigot Watchdog Thread/ERROR]: net.minecraft.server.MinecraftServer$$Lambda$4341/0x000000080141eb68.run(Unknown Source) [19:24:45] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.Thread.run(Thread.java:833) [19:24:45] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:45] [Spigot Watchdog Thread/ERROR]: Entire Thread Dump: [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Reference Handler [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 2 | Suspended: false | Native: false | State: RUNNABLE [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.Reference.waitForReferencePendingList(Native Method) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.Reference.processPendingReferences(Reference.java:253) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.Reference$ReferenceHandler.run(Reference.java:215) [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Finalizer [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 3 | Suspended: false | Native: false | State: WAITING [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.Object.wait(Native Method) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:172) [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Signal Dispatcher [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 4 | Suspended: false | Native: false | State: RUNNABLE [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Notification Thread [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 20 | Suspended: false | Native: false | State: RUNNABLE [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Common-Cleaner [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 21 | Suspended: false | Native: false | State: TIMED_WAITING [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.Object.wait(Native Method) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.lang.Thread.run(Thread.java:833) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:162) [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: DestroyJavaVM [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 23 | Suspended: false | Native: false | State: RUNNABLE [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Worker-Bootstrap-1 [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 29 | Suspended: false | Native: false | State: WAITING [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:341) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:1724) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1623) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [19:24:46] [Spigot Watchdog Thread/ERROR]: Current Thread: Worker-Bootstrap-2 [19:24:46] [Spigot Watchdog Thread/ERROR]: PID: 30 | Suspended: false | Native: false | State: WAITING [19:24:46] [Spigot Watchdog Thread/ERROR]: Stack: [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:341) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:1724) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1623) [19:24:46] [Spigot Watchdog Thread/ERROR]: java.base@17.0.1/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [19:24:46] [Spigot Watchdog Thread/ERROR]: ------------------------------ [Truncated, too long for post] |
Comment by Eccentric Devotion [ 04/Mar/22 ] |
Having similar issues.
Also seeing repeated lines in Spigot log - don't know if it is related: Starting server Loading libraries, please wait... [13:21:37] [ServerMain/INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD' [13:21:54] [Worker-Main-13/INFO]: Loaded 7 recipes [13:21:37] [ServerMain/INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD' [13:21:54] [Worker-Main-13/INFO]: Loaded 7 recipes [13:22:01] [Server thread/INFO]: Starting minecraft server version 1.18.2 Have tested on Windows/Mac, SSD/HDD, increased server-timeout etc |
Comment by gizmo [ 03/Mar/22 ] |
Disabling watchdog had no effect, the same thing happenned with identical log output as the original log I attached. Setting sync-chunk-writes to false also had no effect. Server is running on an SSD, it's an m.2. |
Comment by Dave B [ 03/Mar/22 ] |
I have had a similar issue with my server. My server is a minigames server where players are teleported into a lobby which isn't one of the main 3 worlds, if the server restarts before the game starts, it will restart all fine, however, if the player is teleported to the main world and then either win or lose the minigame, when the server tries to shutdown it gets stuck on the saving world messages. I, however, don't have any crash messages. It will stay in that state forever as far as I have tested. I am also using an SSD. Here is a video showing what I mean: https://drive.google.com/file/d/1MjxtBfAx6gPJRuvH0TBgIFKIEVi6ONRw/view?usp=sharing First time using this so let me know if I need to do something else/done something wrong |
Comment by Marvin Rieple [ 03/Mar/22 ] |
Can you try setting sync-chunk-writes to false in server.properties and also which type of drive do you have HDD / SSD? |
Comment by gizmo [ 03/Mar/22 ] |
I did some tests, new steps to reproduce: 1: teleport your player to a point outside of an area where spawn chunks will be loaded. (1000, ~, 1000 or whatever) 2: restart server to ensure spawn chunks aren't loaded. 3: install the attached plugin on your server. (it's a minimal reproducer jar). 4: log in and alter the world. (break some blocks) 5: shutdown the server. (/stop command) The tests I did today seem to indicate that this issue only occurs if the spawn chunks haven't been loaded. I have been able to reproduce this with the new steps on both a previously 1.18.1 server that had been force upgraded to 1.18.2, as well as freshly made 1.18.2 server. I was able to reproduce on Oracle's jdk 17.0.1 as well as zulu |
Comment by md_5 [ 02/Mar/22 ] |
I cannot reproduce. Try increasing watchdog time and waiting? |
Comment by Doc [ 02/Mar/22 ] |
hmm i dont test but maybe can be for use the method when the world its initializing (in base of the event), because the event its called when the world are in init phase and not chunks are available. |