C2ME soft-bricks on joins when running Shenandoah GC
soupglasses opened this issue ยท 5 comments
Describe the bug
This is partial follow up and similar to the issues on #123
I did some digging on lag spikes when joining a server since my server kept kicking people off it in huge lag spikes. I run the render distance on 32, stats are all from after a fresh server restart.
| Arguments | Overloaded on join? |
|---|---|
| With default Java 19 | Running 6969ms or 139 ticks behind |
| With Hilltty flags (Shenandoah GC) | Running 45362ms or 907 ticks behind |
| With Aikar flags (G1GC) | Running 2867ms or 57 ticks behind |
Hilltty (Shenandoah GC) on C2ME will end up soft bricking even beefy servers because it takes so long to get past first joins, as it keeps kicking anyone joining from timeouts. How C2ME gridlocks itself on Shenandoah GC should be considered a bug.
Sometimes i have also seen hundreds of lines of errors following this pattern when on Hilltty:
May 18 20:02:01 nona minecraft-server[2064]: [20:01:56] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -103079215066 took too long (> 1min)
The Shenandoah GC flags: -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC -XX:ShenandoahGCMode=iu -XX:+UseNUMA -XX:+AlwaysPreTouch -XX:+DisableExplicitGC.
To Reproduce
Steps to reproduce the behavior:
- Install Minecraft 1.19.4 + Fabric + C2ME + Lithium + Starlight.
- Run through openjdk-headless 19 with the above flags.
- Attempt to join and watch it gridlock itself with 100% cpu usage.
Expected behavior
It boots up without any stutters or time outs.
Screenshots
N/A, only relevant screen would be the leave message of "Timed out".
Runtime info (please complete the following information):
- OS:
NixOS 23.05 - Minecraft version:
Minecraft 1.19.4 with Fabric Loader 0.14.19 - Mod version:
c2me-fabric-mc1.19.4-0.2.0+alpha.10.51.jarfrom Modrinth. - Mod branch: (fill this if you are not using the default
verbranches)
Crash reports / logs
The Chunk read at pos [...] took too long
[... snip ...]
May 18 19:56:36 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986157 took too long (> 1min)
May 18 19:56:36 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986156 took too long (> 1min)
May 18 19:56:36 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986155 took too long (> 1min)
May 18 19:56:36 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986154 took too long (> 1min)
May 18 19:56:36 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986153 took too long (> 1min)
May 18 19:56:38 nona systemd[1]: minecraft-server.service: Stopping timed out. Terminating.
May 18 19:56:38 nona systemd[1]: minecraft-server.service: Control process exited, code=killed, status=15/TERM
May 18 19:57:38 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986152 took too long (> 1min)
May 18 19:57:38 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986151 took too long (> 1min)
May 18 19:57:38 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986150 took too long (> 1min)
May 18 19:57:38 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986149 took too long (> 1min)
May 18 19:57:38 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986148 took too long (> 1min)
May 18 19:57:44 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -133143986147 took too long (> 1min)
May 18 19:57:44 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -128849018867 took too long (> 1min)
May 18 19:57:44 nona minecraft-server[1473]: [19:56:33] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos -128849018866 took too long (> 1min)
[... snip ...]
May 18 19:57:49 nona minecraft-server[1473]: [19:57:44] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos 137438953511 took too long (> 1min)
May 18 19:57:49 nona minecraft-server[1473]: [19:57:44] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos 141733920807 took too long (> 1min)
May 18 19:57:49 nona minecraft-server[1473]: [19:57:44] [CompletableFutureDelayScheduler/WARN]: Chunk read at pos 146028888103 took too long (> 1min)
May 18 19:58:08 nona systemd[1]: minecraft-server.service: State 'stop-sigterm' timed out. Killing.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1473 (java) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1476 (java) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1477 (Shenandoah GC T) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1479 (Shenandoah GC T) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1482 (Reference Handl) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1484 (Signal Dispatch) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1486 (Monitor Deflati) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1491 (VM Periodic Tas) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1492 (Common-Cleaner) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1501 (Log4j2-AsyncApp) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1502 (Log4j2-AsyncApp) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1503 (Log4j2-AsyncApp) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1517 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1521 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1522 (Worker-Main-1) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1523 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1526 (Server thread) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1527 (HttpClient-1-Se) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1528 (spark-monitorin) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1532 (spark-async-sam) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1535 (DefaultDispatch) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1538 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1539 (Netty Epoll Acc) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1540 (C2ME Storage #1) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1541 (C2ME Storage #2) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1542 (C2ME Storage #3) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1543 (C2ME Storage #4) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1544 (C2ME Storage #5) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1545 (DefaultDispatch) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1556 (DefaultDispatch) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1557 (DefaultDispatch) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1560 (C2ME Storage #6) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1561 (C2ME Storage #7) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1562 (C2ME Storage #8) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1563 (C2ME Storage #9) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1565 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1566 (CompletableFutu) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1567 (C2ME worker #1) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1568 (C2ME worker #2) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1570 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1574 (Server Watchdog) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1575 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1576 (Thread-35) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1577 (Thread-36) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1596 (Netty Epoll Log) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1602 (Threadly clock ) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1603 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1617 (Netty Epoll Log) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1618 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1632 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1636 (HandshakeComple) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1644 (Async-profiler ) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 1665 (User Authentica) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 2046 (SIGTERM handler) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Killing process 2051 (n/a) with signal SIGKILL.
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Main process exited, code=killed, status=9/KILL
May 18 19:58:08 nona systemd[1]: minecraft-server.service: Failed with result 'timeout'.
Other mods
Mod list
c2me-fabric-mc1.19.4-0.2.0+alpha.10.51.jar
lithium-fabric-mc1.19.4-0.11.1.jar
starlight-1.1.1+fabric.ae22326.jar
spark-1.10.37-fabric.jar
memoryleakfix-fabric-1.17+-1.0.0.jar
krypton-0.2.2.jar
fabric-api-0.81.1+1.19.4.jar
Checklist
- I am using the official version of the mod.
- I tried the latest development version but the issue persists.
- I searched for similar open issues and could not find an existing bug report on this.
Additional context
Quickly doubled it to 4G to test, it still acts the same. Only tested Aikar, but it now also takes exactly double the time on first joins: Running 4762ms or 95 ticks behind.
Looks like a duplicate of #213
Duplicate of #213