feat: basic deadlock debugging facilities

c2me-base/src/main/java/com/ishland/c2me/base/common/threadstate/RunningWork.java

@@ -0,0 +1,7 @@
+package com.ishland.c2me.base.common.threadstate;
+
+public interface RunningWork {
+
+    String toString();
+
+}

c2me-base/src/main/java/com/ishland/c2me/base/common/threadstate/SyncLoadWork.java

@@ -0,0 +1,14 @@
+package com.ishland.c2me.base.common.threadstate;
+
+import net.minecraft.server.world.ServerWorld;
+import net.minecraft.util.math.ChunkPos;
+import net.minecraft.world.chunk.ChunkStatus;
+
+public record SyncLoadWork(ServerWorld world, ChunkPos chunkPos, ChunkStatus targetStatus, boolean create) implements RunningWork {
+
+    @Override
+    public String toString() {
+        return String.format("Sync load chunk %s to status %s in world %s (create=%s)", chunkPos, targetStatus, world.getRegistryKey().getValue(), create);
+    }
+
+}

c2me-base/src/main/java/com/ishland/c2me/base/common/threadstate/ThreadInstrumentation.java

@@ -0,0 +1,80 @@
+package com.ishland.c2me.base.common.threadstate;
+
+import com.google.common.util.concurrent.ThreadFactoryBuilder;
+
+import java.lang.management.ThreadInfo;
+import java.util.Collections;
+import java.util.Map;
+import java.util.Set;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.Executors;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.TimeUnit;
+
+public class ThreadInstrumentation {
+
+    private static final ScheduledExecutorService CLEANER = Executors.newSingleThreadScheduledExecutor(
+            new ThreadFactoryBuilder()
+                    .setNameFormat("ThreadStateHolderCleaner")
+                    .setDaemon(true)
+                    .build()
+    );
+
+    private static final ConcurrentHashMap<Thread, ThreadState> threadStateMap = new ConcurrentHashMap<>();
+
+    private static final ThreadLocal<ThreadState> threadStateThreadLocal = ThreadLocal.withInitial(() -> getOrCreate(Thread.currentThread()));
+
+    static {
+        CLEANER.scheduleAtFixedRate(
+                () -> threadStateMap.entrySet().removeIf(entry -> !entry.getKey().isAlive()),
+                30,
+                30,
+                TimeUnit.SECONDS
+        );
+    }
+
+    public static ThreadState getOrCreate(Thread thread) {
+        return threadStateMap.computeIfAbsent(thread, unused -> new ThreadState());
+    }
+
+    public static ThreadState get(Thread thread) {
+        return threadStateMap.get(thread);
+    }
+
+    public static ThreadState getCurrent() {
+        return threadStateThreadLocal.get();
+    }
+
+    public static String printState(ThreadInfo threadInfo) {
+        return printState(threadInfo.getThreadName(), threadInfo.getThreadId(), findFromTid(threadInfo.getThreadId()));
+    }
+
+    public static Set<Map.Entry<Thread, ThreadState>> entrySet() {
+        return Collections.unmodifiableSet(threadStateMap.entrySet());
+    }
+
+    public static String printState(String name, long tid, ThreadState state) {
+        if (state != null) {
+            RunningWork[] runningWorks = state.toArray();
+            if (runningWorks.length != 0) {
+                StringBuilder builder = new StringBuilder();
+                builder.append("Task trace for thread \"").append(name).append("\" Id=").append(tid).append(" (obtained on a best-effort basis)\n");
+                for (RunningWork runningWork : runningWorks) {
+                    builder.append(runningWork.toString().indent(4)).append("\n");
+                }
+                return builder.toString();
+            }
+        }
+        return null;
+    }
+
+    private static ThreadState findFromTid(long tid) {
+        for (Map.Entry<Thread, ThreadState> entry : threadStateMap.entrySet()) {
+            if (entry.getKey().threadId() == tid) {
+                return entry.getValue();
+            }
+        }
+        return null;
+    }
+
+}

c2me-base/src/main/java/com/ishland/c2me/base/common/threadstate/ThreadState.java

@@ -0,0 +1,62 @@
+package com.ishland.c2me.base.common.threadstate;
+
+import java.io.Closeable;
+import java.util.ArrayDeque;
+import java.util.concurrent.locks.ReentrantReadWriteLock;
+
+public class ThreadState {
+
+    private final ArrayDeque<RunningWork> runningWorks = new ArrayDeque<>();
+    private final ReentrantReadWriteLock lock = new ReentrantReadWriteLock();
+
+    public void push(RunningWork runningWork) {
+        lock.writeLock().lock();
+        try {
+            runningWorks.push(runningWork);
+        } finally {
+            lock.writeLock().unlock();
+        }
+    }
+
+    public void pop(RunningWork runningWork) {
+        lock.writeLock().lock();
+        try {
+            RunningWork popped = runningWorks.peek();
+            if (popped != runningWork) {
+                IllegalArgumentException exception = new IllegalArgumentException("Corrupt ThreadState");
+                exception.printStackTrace();
+                throw exception;
+            }
+            runningWorks.pop();
+        } finally {
+            lock.writeLock().unlock();
+        }
+    }
+
+    public WorkClosable begin(RunningWork runningWork) {
+        lock.writeLock().lock();
+        try {
+            runningWorks.push(runningWork);
+            return new WorkClosable(this, runningWork);
+        } finally {
+            lock.writeLock().unlock();
+        }
+    }
+
+    public RunningWork[] toArray() {
+        lock.readLock().lock();
+        try {
+            return runningWorks.toArray(RunningWork[]::new);
+        } finally {
+            lock.readLock().unlock();
+        }
+    }
+
+    public static record WorkClosable(ThreadState state, RunningWork work) implements Closeable {
+        @Override
+        public void close() {
+            state.pop(work);
+        }
+    }
+
+}

c2me-base/src/main/java/com/ishland/c2me/base/mixin/priority/MixinServerChunkManager.java → c2me-base/src/main/java/com/ishland/c2me/base/mixin/instrumentation/MixinServerChunkManager.java

@@ -1,10 +1,16 @@
-package com.ishland.c2me.base.mixin.priority;
+package com.ishland.c2me.base.mixin.instrumentation;
 
 import com.ishland.c2me.base.common.scheduler.ISyncLoadManager;
 import com.ishland.c2me.base.common.scheduler.IVanillaChunkManager;
+import com.ishland.c2me.base.common.threadstate.SyncLoadWork;
+import com.ishland.c2me.base.common.threadstate.ThreadInstrumentation;
+import com.llamalad7.mixinextras.injector.wrapmethod.WrapMethod;
+import com.llamalad7.mixinextras.injector.wrapoperation.Operation;
+import com.llamalad7.mixinextras.injector.wrapoperation.WrapOperation;
 import net.minecraft.server.world.ChunkHolder;
 import net.minecraft.server.world.ServerChunkLoadingManager;
 import net.minecraft.server.world.ServerChunkManager;
+import net.minecraft.server.world.ServerWorld;
 import net.minecraft.util.math.ChunkPos;
 import net.minecraft.world.chunk.Chunk;
 import net.minecraft.world.chunk.ChunkStatus;
@@ -15,9 +21,6 @@
 import org.spongepowered.asm.mixin.Shadow;
 import org.spongepowered.asm.mixin.Unique;
 import org.spongepowered.asm.mixin.injection.At;
-import org.spongepowered.asm.mixin.injection.Inject;
-import org.spongepowered.asm.mixin.injection.Redirect;
-import org.spongepowered.asm.mixin.injection.callback.CallbackInfoReturnable;
 
 import java.util.function.BooleanSupplier;
 
@@ -36,26 +39,41 @@ public abstract class MixinServerChunkManager implements ISyncLoadManager {
     protected abstract ChunkHolder getChunkHolder(long pos);
 
     @Shadow @Final public ServerChunkLoadingManager chunkLoadingManager;
+    @Shadow @Final private ServerWorld world;
     @Unique
     private volatile ChunkPos currentSyncLoadChunk = null;
     @Unique
     private volatile long syncLoadNanos = 0;
 
     @Dynamic
-    @Redirect(method = {
+    @WrapOperation(method = {
             "getChunk(IILnet/minecraft/world/chunk/ChunkStatus;Z)Lnet/minecraft/world/chunk/Chunk;",
             "getChunkBlocking(IILnet/minecraft/world/chunk/ChunkStatus;Z)Lnet/minecraft/world/chunk/Chunk;",
             },
             at = @At(value = "INVOKE", target = "Lnet/minecraft/server/world/ServerChunkManager$MainThreadExecutor;runTasks(Ljava/util/function/BooleanSupplier;)V"), require = 0)
-    private void beforeAwaitChunk(ServerChunkManager.MainThreadExecutor instance, BooleanSupplier supplier, int x, int z, ChunkStatus leastStatus, boolean create) {
-        if (Thread.currentThread() != this.serverThread || supplier.getAsBoolean()) return;
+    private void instrumentAwaitChunk(ServerChunkManager.MainThreadExecutor instance, BooleanSupplier stopCondition, Operation<Void> original, int x, int z, ChunkStatus leastStatus, boolean create) {
+        if (Thread.currentThread() != this.serverThread || stopCondition.getAsBoolean()) return;
 
         this.currentSyncLoadChunk = new ChunkPos(x, z);
         syncLoadNanos = System.nanoTime();
         ((IVanillaChunkManager) this.chunkLoadingManager).c2me$getSchedulingManager().setCurrentSyncLoad(this.currentSyncLoadChunk);
-        instance.runTasks(supplier);
-        ((IVanillaChunkManager) this.chunkLoadingManager).c2me$getSchedulingManager().setCurrentSyncLoad(null);
-        this.currentSyncLoadChunk = null;
+        try (var ignored = ThreadInstrumentation.getCurrent().begin(new SyncLoadWork(this.world, new ChunkPos(x, z), leastStatus, create))) {
+            original.call(instance, stopCondition);
+        } finally {
+            ((IVanillaChunkManager) this.chunkLoadingManager).c2me$getSchedulingManager().setCurrentSyncLoad(null);
+            this.currentSyncLoadChunk = null;
+        }
+    }
+
+    @WrapMethod(method = "getChunk(IILnet/minecraft/world/chunk/ChunkStatus;Z)Lnet/minecraft/world/chunk/Chunk;")
+    private Chunk instrumentGetChunk(int x, int z, ChunkStatus leastStatus, boolean create, Operation<Chunk> original) {
+        if (Thread.currentThread() != this.serverThread) {
+            try (var ignored = ThreadInstrumentation.getCurrent().begin(new SyncLoadWork(this.world, new ChunkPos(x, z), leastStatus, create))) {
+                return original.call(x, z, leastStatus, create);
+            }
+        } else {
+            return original.call(x, z, leastStatus, create);
+        }
     }
 
     @Override

c2me-base/src/main/java/com/ishland/c2me/base/mixin/report/MixinDedicatedServerWatchdog.java

@@ -0,0 +1,60 @@
+package com.ishland.c2me.base.mixin.report;
+
+import com.ishland.c2me.base.common.threadstate.ThreadInstrumentation;
+import com.ishland.c2me.base.common.threadstate.ThreadState;
+import com.llamalad7.mixinextras.sugar.Local;
+import net.minecraft.server.dedicated.DedicatedServerWatchdog;
+import net.minecraft.util.crash.CrashReport;
+import net.minecraft.util.crash.CrashReportSection;
+import org.slf4j.Logger;
+import org.spongepowered.asm.mixin.Final;
+import org.spongepowered.asm.mixin.Mixin;
+import org.spongepowered.asm.mixin.Shadow;
+import org.spongepowered.asm.mixin.injection.At;
+import org.spongepowered.asm.mixin.injection.Inject;
+import org.spongepowered.asm.mixin.injection.callback.CallbackInfoReturnable;
+import org.spongepowered.asm.mixin.injection.callback.LocalCapture;
+
+import java.lang.management.ThreadInfo;
+import java.lang.management.ThreadMXBean;
+import java.util.Map;
+
+@Mixin(DedicatedServerWatchdog.class)
+public class MixinDedicatedServerWatchdog {
+
+    @Shadow @Final private static Logger LOGGER;
+
+    @Inject(method = "createCrashReport", at = @At(value = "INVOKE", target = "Ljava/lang/management/ThreadInfo;getThreadId()J"))
+    private static void prependThreadInstrumentation(String message, long threadId, CallbackInfoReturnable<CrashReport> cir, @Local StringBuilder stringBuilder, @Local ThreadInfo threadInfo) {
+        String state = null;
+        try {
+            state = ThreadInstrumentation.printState(threadInfo);
+        } catch (Throwable t) {
+            LOGGER.error("Failed to fetch state for thread {}", threadInfo);
+        }
+        if (state != null) {
+            stringBuilder.append(state);
+        }
+    }
+
+    @Inject(method = "createCrashReport", at = @At(value = "INVOKE", target = "Lnet/minecraft/util/crash/CrashReport;addElement(Ljava/lang/String;)Lnet/minecraft/util/crash/CrashReportSection;", ordinal = 0), locals = LocalCapture.CAPTURE_FAILHARD)
+    private static void addInstrumentationData(String message, long threadId, CallbackInfoReturnable<CrashReport> cir, ThreadMXBean threadMXBean, ThreadInfo[] threadInfos, StringBuilder stringBuilder, Error error, CrashReport crashReport) {
+        CrashReportSection section = crashReport.addElement("Thread trace dump (obtained on a best-effort basis)");
+        try {
+            for (Map.Entry<Thread, ThreadState> entry : ThreadInstrumentation.entrySet()) {
+                try {
+                    Thread thread = entry.getKey();
+                    String state = ThreadInstrumentation.printState(thread.getName(), thread.threadId(), entry.getValue());
+                    if (state != null) {
+                        section.add(thread.getName(), state);
+                    }
+                } catch (Throwable t) {
+                    LOGGER.error("Failed to dumping state for thread {}", entry.getKey(), t);
+                }
+            }
+        } catch (Throwable t) {
+            LOGGER.error("Failed to dump all known thread states", t);
+        }
+    }
+
+}

c2me-base/src/main/resources/c2me-base.mixins.json

@@ -50,7 +50,8 @@
     "access.IXoroshiro128PlusPlusRandom",
     "access.IXoroshiro128PlusPlusRandomDeriver",
     "access.IXoroshiro128PlusPlusRandomImpl",
-    "priority.MixinServerChunkManager",
+    "instrumentation.MixinServerChunkManager",
+    "report.MixinDedicatedServerWatchdog",
     "scheduler.MixinThreadedAnvilChunkStorage",
     "theinterface.MixinStorageIoWorker",
     "util.log4j2shutdownhookisnomore.MixinMain",