Lag outside of an Edit / ThreadLocal kills interactions
octylFractal opened this issue ยท 10 comments
WorldEdit Version
7.2.x, 7.3.0-SNAPSHOT
Platform Version
Any Bukkit Platform, Maybe All
Bug Description
ThreadLocals have a weird bug that can slow down interact events to a crawl, #1668. We might be able to implement some sort of hack to only have it slow down those with WorldEdit permissions, preventing TPS hits. Or we could just try to fix the bug, either with a WorldEdit refactor or JVM report / patch.
Expected Behavior
TPS is fine and the JVM actually works.
Reproduction Steps
????
TODO
Note: this issue is for discussion of some sort of solution to this problem, which currently has an unknown cause but is 100% confirmed.
Hello, I believe the patch #1862 should be included in the release of WE 7.2.6 on Aug 22, but we still encountered similar issue on latest tuinity-paperclip (1.16.5) and WE 7.2.6 recently.
Please refer to the following stacktrace:
[19:29:02] [Paper Watchdog Thread/ERROR]: Current Thread: Server thread
[19:29:02] [Paper Watchdog Thread/ERROR]: PID: 44 | Suspended: false | Native: false | State: RUNNABLE
[19:29:02] [Paper Watchdog Thread/ERROR]: Stack:
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.ThreadLocal$ThreadLocalMap.expungeStaleEntry(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.ThreadLocal$ThreadLocalMap.remove(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.ThreadLocal.remove(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.session.request.Request.reset(Request.java:111)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.extension.platform.PlatformManager.handlePlayerInput(PlatformManager.java:439)
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.invoke.ReceiverBoundHandle.invokeExact_thunkArchetype_V(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.invoke.AsTypeHandle.invokeExact_thunkArchetype_X(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.util.eventbus.MethodHandleEventHandler.dispatch(MethodHandleEventHandler.java:51)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.util.eventbus.EventHandler.handleEvent(EventHandler.java:73)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.util.eventbus.EventBus.dispatch(EventBus.java:193)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.util.eventbus.EventBus.post(EventBus.java:181)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.WorldEdit.handleArmSwing(WorldEdit.java:627)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.sk89q.worldedit.bukkit.WorldEditListener.onPlayerInteract(WorldEditListener.java:128)
[19:29:02] [Paper Watchdog Thread/ERROR]: com.destroystokyo.paper.event.executor.asm.generated.GeneratedEventExecutor19.execute(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.EventExecutor.lambda$create$1(EventExecutor.java:69)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.EventExecutor$$Lambda$4861/0x0000000000000000.execute(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: co.aikar.timings.TimedEventExecutor.execute(TimedEventExecutor.java:80)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:70)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:624)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.craftbukkit.v1_16_R3.event.CraftEventFactory.callPlayerInteractEvent(CraftEventFactory.java:549)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.craftbukkit.v1_16_R3.event.CraftEventFactory.callPlayerInteractEvent(CraftEventFactory.java:512)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.craftbukkit.v1_16_R3.event.CraftEventFactory.callPlayerInteractEvent(CraftEventFactory.java:507)
[19:29:02] [Paper Watchdog Thread/ERROR]: org.bukkit.craftbukkit.v1_16_R3.event.CraftEventFactory.callPlayerInteractEvent(CraftEventFactory.java:503)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.PlayerConnection.a(PlayerConnection.java:2305)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.PacketPlayInArmAnimation.a(PacketPlayInArmAnimation.java:29)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.PacketPlayInArmAnimation.a(PacketPlayInArmAnimation.java:8)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.PlayerConnectionUtils.lambda$ensureMainThread$1(PlayerConnectionUtils.java:55)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.PlayerConnectionUtils$$Lambda$5986/0x0000000000000000.run(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.TickTask.run(SourceFile:18)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.IAsyncTaskHandler.executeTask(IAsyncTaskHandler.java:136)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.IAsyncTaskHandlerReentrant.executeTask(SourceFile:23)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.IAsyncTaskHandler.executeNext(IAsyncTaskHandler.java:109)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer.bb(MinecraftServer.java:1325)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer.executeNext(MinecraftServer.java:1318)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.IAsyncTaskHandler.executeAll(IAsyncTaskHandler.java:95)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer.a(MinecraftServer.java:1455)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer.w(MinecraftServer.java:1134)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer.lambda$a$0(MinecraftServer.java:292)
[19:29:02] [Paper Watchdog Thread/ERROR]: net.minecraft.server.v1_16_R3.MinecraftServer$$Lambda$3143/0x0000000000000000.run(Unknown Source)
[19:29:02] [Paper Watchdog Thread/ERROR]: java.base/java.lang.Thread.run(Unknown Source)
Hope this helps further on this case.
Thanks!
We opted to remove the patch as we think a patch included in Paper should fix this. Unfortunately I think that only made it into 1.17 Paper.
As a follow-up, the relevant PR: PaperMC/Paper#6325. You could try applying it to a custom Paper 1.16.5 build.
Closing as this appears resolved, please comment here if you experience this with the above patch active (any recent 1.17 paper will have it).
Worth noting that this can only be reproduced with G1GC-based garbage collectors, the CMS GC does not exhibit this behaviour.
Relevant ElasticSearch thread on the issue: https://discuss.elastic.co/t/indexing-performance-degrading-over-time/40229
Prior JDK issue: https://bugs.openjdk.java.net/browse/JDK-8182982
The above issue was closed, mainly due to not enough information on how to reliably reproduce in order to prove that it's actually a Java bug.
"G1GC-based" is an odd term, but that essentially means ZGC and Shenandoah as well, right? They're not really the same kind as G1GC, just have some similar flaw.
Same issue on
- Ubuntu Server 20.04.2 LTS x86_64
- CPU: i7-3770
- Manually compiled jdk15u
- Flags:
-Xms10G -Xmx10G -XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:MaxGCPauseMillis=200 -XX:+UnlockExperimentalVMOptions -XX:+DisableExplicitGC -XX:+AlwaysPreTouch -XX:G1NewSizePercent=30 -XX:G1MaxNewSizePercent=40 -XX:G1HeapRegionSize=8M -XX:G1ReservePercent=20 -XX:G1HeapWastePercent=5 -XX:G1MixedGCCountTarget=4 -XX:InitiatingHeapOccupancyPercent=15 -XX:G1MixedGCLiveThresholdPercent=90 -XX:G1RSetUpdatingPauseTimePercent=5 -XX:SurvivorRatio=32 -XX:+PerfDisableSharedMem -XX:MaxTenuringThreshold=1 -Dusing.aikars.flags=https://mcflags.emc.gs -Daikars.new.flags=true -XX:+EnableJVMCI -XX:+UseJVMCICompiler
JDK was compiled using:
git clone --recursive https://github.com/openjdk/jdk15u
cd jdk15u/
bash configure --with-jvm-variants=server --with-jvm-features=link-time-opt --with-extra-cflags='-Ofast -fgraphite-identity -floop-nest-optimize -fdevirtualize-at-ltrans -fipa-pta -fno-semantic-interposition -fuse-linker-plugin -march=native -mtune=native -pipe' --with-extra-cxxflags='-Ofast -fgraphite-identity -floop-nest-optimize -fdevirtualize-at-ltrans -fipa-pta -fno-semantic-interposition -fuse-linker-plugin -march=native -mtune=native -pipe' --disable-warnings-as-errors --enable-headless-only=yes && make images
Also tried on vanilla jdk 15 yesterday, it happens.