Added WIP packet dumper.

patches/net/minecraft/network/NetworkManager.java.patch

@@ -1,6 +1,16 @@
 --- ../src-base/minecraft/net/minecraft/network/NetworkManager.java
 +++ ../src-work/minecraft/net/minecraft/network/NetworkManager.java
-@@ -25,6 +25,8 @@
+@@ -6,6 +6,9 @@
+ import cpw.mods.fml.common.network.internal.FMLProxyPacket;
+ import cpw.mods.fml.relauncher.Side;
+ import cpw.mods.fml.relauncher.SideOnly;
++import io.github.crucible.CrucibleConfigs;
++import io.github.crucible.CrucibleModContainer;
++import io.github.crucible.util.Stringify;
+ import io.netty.bootstrap.Bootstrap;
+ import io.netty.channel.Channel;
+ import io.netty.channel.ChannelException;
+@@ -25,6 +28,8 @@
  import java.net.InetAddress;
  import java.net.SocketAddress;
  import java.util.Queue;
@@ -9,16 +19,17 @@
  import javax.crypto.SecretKey;
  import net.minecraft.util.ChatComponentTranslation;
  import net.minecraft.util.CryptManager;
-@@ -38,6 +40,8 @@
+@@ -38,6 +43,9 @@
  import org.apache.logging.log4j.Logger;
  import org.apache.logging.log4j.Marker;
  import org.apache.logging.log4j.MarkerManager;
 +import com.mojang.authlib.properties.Property;
 +import com.google.common.collect.ImmutableSet; // Spigot
++import org.spigotmc.WatchdogThread;
 
  public class NetworkManager extends SimpleChannelInboundHandler
  {
-@@ -54,13 +58,32 @@
+@@ -54,13 +62,32 @@
      private final Queue receivedPacketsQueue = Queues.newConcurrentLinkedQueue();
      private final Queue outboundPacketsQueue = Queues.newConcurrentLinkedQueue();
      private Channel channel;
@@ -52,23 +63,23 @@
      public NetworkManager(boolean p_i45147_1_)
      {
          this.isClientSide = p_i45147_1_;
-@@ -71,6 +94,7 @@
+@@ -71,6 +98,7 @@
          super.channelActive(p_channelActive_1_);
          this.channel = p_channelActive_1_.channel();
          this.socketAddress = this.channel.remoteAddress();
 +        this.field_152463_r = false; // Spigot
          this.setConnectionState(EnumConnectionState.HANDSHAKING);
      }
 
-@@ -128,6 +152,7 @@
+@@ -128,6 +156,7 @@
 
      public void scheduleOutboundPacket(Packet p_150725_1_, GenericFutureListener ... p_150725_2_)
      {
 +        if (p_150725_1_ == null) return;
          if (this.channel != null && this.channel.isOpen())
          {
              this.flushOutboundQueue();
-@@ -181,9 +206,9 @@
+@@ -181,9 +210,9 @@
      {
          if (this.channel != null && this.channel.isOpen())
          {
@@ -80,11 +91,19 @@
                  this.dispatchPacket(inboundhandlertuplepacketlistener.field_150774_a, inboundhandlertuplepacketlistener.field_150773_b);
              }
          }
-@@ -208,7 +233,15 @@
+@@ -206,13 +235,45 @@
+
+         if (this.netHandler != null)
          {
++            // Crucible start - track player for watchdog
++            if (netHandler instanceof NetHandlerPlayServer) {
++                WatchdogThread.currentPlayer.set(((NetHandlerPlayServer) netHandler).playerEntity);
++            }
++            // Crucible end
              for (int i = 1000; !this.receivedPacketsQueue.isEmpty() && i >= 0; --i)
              {
 -                Packet packet = (Packet)this.receivedPacketsQueue.poll();
+-                packet.processPacket(this.netHandler);
 +                Packet packet = (Packet) this.receivedPacketsQueue.poll();
 +
 +                // CraftBukkit start
@@ -94,10 +113,33 @@
 +                }
 +
 +                // CraftBukkit end
-                 packet.processPacket(this.netHandler);
++                // Crucible start - add packet timeout and logging
++                long start = System.currentTimeMillis();
++                WatchdogThread.currentPacket.set(packet);
++
++                packet.processPacket(this.netHandler); // Original code
++
++                if (CrucibleConfigs.configs.crucible_logging_packetTimeout) {
++                    long end = (System.currentTimeMillis() - start);
++                    if (end > CrucibleConfigs.configs.crucible_logging_packetTimeoutMs) {
++                        CrucibleModContainer.logger.warn("Packet processing took too long!!!");
++                        if (netHandler instanceof NetHandlerPlayServer) {
++                            NetHandlerPlayServer server = (NetHandlerPlayServer) netHandler;
++                            CrucibleModContainer.logger.warn("Player: {}", server.playerEntity);
++                        }
++                        CrucibleModContainer.logger.warn("packet: {}", Stringify.describePacket(packet));
++                    }
++                }
++                WatchdogThread.currentPacket.set(null);
++                // Crucible end
              }
 
-@@ -225,11 +258,14 @@
+             this.netHandler.onNetworkTick();
++            WatchdogThread.currentPlayer.set(null); // Crucible - track player
+         }
+
+         this.channel.flush();
+@@ -225,11 +286,14 @@
 
      public void closeChannel(IChatComponent p_150718_1_)
      {
@@ -112,7 +154,7 @@
      }
 
      public boolean isLocalChannel()
-@@ -254,7 +290,7 @@
+@@ -254,7 +318,7 @@
                  {
                      ;
                  }
@@ -121,7 +163,7 @@
                  try
                  {
                      p_initChannel_1_.config().setOption(ChannelOption.TCP_NODELAY, Boolean.valueOf(false));
-@@ -322,6 +358,13 @@
+@@ -322,6 +386,13 @@
          return channel;
      }
 

src/main/java/io/github/crucible/CrucibleConfigs.java

@@ -150,6 +150,12 @@ public class CrucibleConfigs extends YamlConfig {
             "Be warned that looking up the caller can have a noticeable performance impact."})
     public boolean crucible_logging_logStdOutCaller = false;
 
+    @Comment("Dump packet information whenever packet processing of a player takes too long.")
+    public boolean crucible_logging_packetTimeout = false;
+
+    @Comment("Maximum time (in milliseconds) a packet can take before getting dumped.")
+    public long crucible_logging_packetTimeoutMs = 500;
+
     @Comment("List of world names where the usage of modded itens and blocks will be disabled for ")
     public List<String> crucible_protectedWorld = Collections.singletonList("spawn");
 

src/main/java/io/github/crucible/util/Stringify.java

@@ -0,0 +1,26 @@
+package io.github.crucible.util;
+
+import net.minecraft.network.Packet;
+import net.minecraft.network.play.client.C03PacketPlayer;
+
+import java.lang.reflect.Field;
+
+public class Stringify {
+
+    public static String describePacket(Packet packet) {
+        StringBuilder sb = new StringBuilder();
+        sb.append(packet.getClass().getName()).append("{\n");
+        for (Field field : packet.getClass().getDeclaredFields()) {
+            try {
+                field.setAccessible(true);
+                sb.append(" [").append(field.getName()).append("@").append(field.getType().getName()).append("] ")
+                        .append(field.get(packet));
+            } catch (IllegalAccessException e) {
+                sb.append("  Error getting field ").append(field.getName()).append(": ").append(e.getMessage());
+            }
+            sb.append("\n");
+        }
+        sb.append("}");
+        return sb.toString();
+    }
+}

src/main/java/org/spigotmc/WatchdogThread.java

@@ -1,6 +1,10 @@
 package org.spigotmc;
 
 import io.github.crucible.CrucibleConfigs;
+import io.github.crucible.util.Stringify;
+import net.minecraft.entity.Entity;
+import net.minecraft.entity.player.EntityPlayerMP;
+import net.minecraft.network.Packet;
 import net.minecraft.server.MinecraftServer;
 import net.minecraftforge.cauldron.CauldronHooks;
 import org.bukkit.Bukkit;
@@ -11,12 +15,14 @@
 import java.lang.management.ThreadInfo;
 import java.text.SimpleDateFormat;
 import java.util.Date;
+import java.util.concurrent.atomic.AtomicReference;
 import java.util.logging.Level;
 import java.util.logging.Logger;
 
 
 public class WatchdogThread extends Thread {
-
+    public static final AtomicReference<Packet> currentPacket = new AtomicReference<>();
+    public static final AtomicReference<EntityPlayerMP> currentPlayer = new AtomicReference<>();
     private static WatchdogThread instance;
     private final long timeoutTime;
     private final long warningTime;
@@ -136,6 +142,21 @@ public void run() {
                     log.log(Level.SEVERE, "Writing complete");
                     log.log(Level.SEVERE, "------------------------------");
                 }
+                Packet packet = currentPacket.get();
+                if (packet != null) {
+
+                    log.log(Level.SEVERE, "------------------------------");
+                    log.log(Level.SEVERE, "Current packet being processed:");
+                    log.log(Level.SEVERE, Stringify.describePacket(packet));
+
+                    EntityPlayerMP player = currentPlayer.get();
+                    if (player != null) {
+                        log.log(Level.SEVERE, "Current player:");
+                        log.log(Level.SEVERE, "  p:" + player);
+                    }
+
+                    log.log(Level.SEVERE, "------------------------------");
+                }
                 // Cauldron end
 
                 log.log(Level.SEVERE, "------------------------------");