diff --git a/patches/net/minecraft/network/NetworkManager.java.patch b/patches/net/minecraft/network/NetworkManager.java.patch index 327aec0b..9a8f04cf 100644 --- a/patches/net/minecraft/network/NetworkManager.java.patch +++ b/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,7 +63,7 @@ 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(); @@ -60,7 +71,7 @@ this.setConnectionState(EnumConnectionState.HANDSHAKING); } -@@ -128,6 +152,7 @@ +@@ -128,6 +156,7 @@ public void scheduleOutboundPacket(Packet p_150725_1_, GenericFutureListener ... p_150725_2_) { @@ -68,7 +79,7 @@ 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; } diff --git a/src/main/java/io/github/crucible/CrucibleConfigs.java b/src/main/java/io/github/crucible/CrucibleConfigs.java index 10e1756c..989d013c 100644 --- a/src/main/java/io/github/crucible/CrucibleConfigs.java +++ b/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 crucible_protectedWorld = Collections.singletonList("spawn"); diff --git a/src/main/java/io/github/crucible/util/Stringify.java b/src/main/java/io/github/crucible/util/Stringify.java new file mode 100644 index 00000000..e615dcca --- /dev/null +++ b/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(); + } +} diff --git a/src/main/java/org/spigotmc/WatchdogThread.java b/src/main/java/org/spigotmc/WatchdogThread.java index 5a72a584..3dbe70b2 100644 --- a/src/main/java/org/spigotmc/WatchdogThread.java +++ b/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 currentPacket = new AtomicReference<>(); + public static final AtomicReference 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, "------------------------------");