WorldEdit

WorldEdit

Mods
42M Downloads

Lag outside of an Edit / ThreadLocal kills interactions

octylFractal opened this issue ยท 10 comments

commented

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.

commented

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!

commented

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.

commented

As a follow-up, the relevant PR: PaperMC/Paper#6325. You could try applying it to a custom Paper 1.16.5 build.

commented

Thanks, will try that out.

commented

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).

commented

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.

commented

"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.

commented

Yeah - as far as I'm aware they share common code

commented

@v9-l10n would you be able to give details on the machine from #1668? I'm wondering if this might be hardware/OS specific, as I haven't really been able to reproduce it at all.

commented

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.