Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

C2ME soft-bricks on joins when running Shenandoah GC #217

Closed
3 tasks done
soupglasses opened this issue May 18, 2023 · 5 comments
Closed
3 tasks done

C2ME soft-bricks on joins when running Shenandoah GC #217

soupglasses opened this issue May 18, 2023 · 5 comments
Labels
bug Something isn't working

Comments

@soupglasses
Copy link

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:

  1. Install Minecraft 1.19.4 + Fabric + C2ME + Lithium + Starlight.
  2. Run through openjdk-headless 19 with the above flags.
  3. 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.jar from Modrinth.
  • Mod branch: (fill this if you are not using the default ver branches)

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

@toinouH
Copy link
Contributor

toinouH commented May 18, 2023

How much did you allocate ?

@soupglasses
Copy link
Author

Currently only 2G for testing.

@soupglasses
Copy link
Author

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.

@ishland
Copy link
Collaborator

ishland commented May 20, 2023

Looks like a duplicate of #213

@ishland
Copy link
Collaborator

ishland commented Jun 3, 2023

Duplicate of #213

@ishland ishland marked this as a duplicate of #213 Jun 3, 2023
@ishland ishland closed this as not planned Won't fix, can't repro, duplicate, stale Jun 3, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants