Corrected deserializedItemStack implementation, custom logging ...

src/config.yml

@@ -3,4 +3,10 @@
 dispatchCommand: ~
 
 # The reason why player was kicked
-kickMessage: 'You tried to exploit CustomPayload packet'
+kickMessage: 'You tried to exploit CustomPayload packet'
+
+# Enable or disabling additional detail log to plugin data folder
+EnableCustomLog: true
+
+# The format of custom log message. See https://docs.oracle.com/javase/8/docs/api/java/util/logging/SimpleFormatter.html#format-java.util.logging.LogRecord-
+CustomLogFormat: "[%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS %4$s]: %5$s%6$s%n"

src/plugin.yml

@@ -1,5 +1,5 @@
 name: CustomPayloadFixer
 main: ru.justblender.bukkit.CustomPayloadFixer
-version: 1.5
+version: 1.5.1 X
 author: justblender
 depend: [ProtocolLib]

src/ru/justblender/PluginLogger/PluginLoggerFormatter.java

@@ -0,0 +1,60 @@
+package ru.justblender.PluginLogger;
+
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.Date;
+import java.util.logging.Formatter;
+import java.util.logging.LogRecord;
+
+public class PluginLoggerFormatter extends Formatter {
+    private static final String DEFAULT_FORMAT = "[%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS %4$s]: %5$s%6$s%n";
+    private final Date dat = new Date();
+    private final String format;
+
+    PluginLoggerFormatter() {
+        this(null);
+    }
+
+    PluginLoggerFormatter(String format) {
+        if (format == null || format.isEmpty()) {
+            format = DEFAULT_FORMAT;
+        }
+        try {
+            //noinspection ResultOfMethodCallIgnored
+            String.format(format, new Date(), "", "", "", "", "");
+        } catch (IllegalArgumentException var3) {
+            format = DEFAULT_FORMAT;
+        }
+        this.format = format;
+    }
+
+    public synchronized String format(LogRecord record) {
+        dat.setTime(record.getMillis());
+        String source;
+        if (record.getSourceClassName() != null) {
+            source = record.getSourceClassName();
+            if (record.getSourceMethodName() != null) {
+                source += " " + record.getSourceMethodName();
+            }
+        } else {
+            source = record.getLoggerName();
+        }
+        String message = formatMessage(record);
+        String throwable = "";
+        if (record.getThrown() != null) {
+            StringWriter sw = new StringWriter();
+            PrintWriter pw = new PrintWriter(sw);
+            pw.println();
+            record.getThrown().printStackTrace(pw);
+            pw.close();
+            throwable = sw.toString();
+        }
+        return String.format(format,
+                dat,
+                source,
+                record.getLoggerName(),
+                record.getLevel().getName(),
+                message,
+                throwable);
+    }
+}

src/ru/justblender/PluginLogger/PluginLoggerHelper.java

@@ -0,0 +1,37 @@
+package ru.justblender.PluginLogger;
+
+import java.io.File;
+import java.io.IOException;
+import java.nio.file.Path;
+import java.nio.file.Paths;
+import java.util.logging.*;
+
+public class PluginLoggerHelper {
+
+    public static java.util.logging.Logger openLogger(File file, String format) throws Throwable {
+        try {
+            Logger logger = Logger.getAnonymousLogger();
+            FileHandler fh;
+            File outDir = file.toPath().getParent().toFile();
+            if (!outDir.exists()) {
+                //noinspection ResultOfMethodCallIgnored
+                outDir.mkdirs();
+            }
+            fh = new FileHandler(file.getAbsolutePath(), 0, 1, true);
+            logger.addHandler(fh);
+            logger.setUseParentHandlers(false);
+            PluginLoggerFormatter formatter = new PluginLoggerFormatter(format);
+            fh.setFormatter(formatter);
+            return logger;
+        } catch (Throwable ex) {
+            throw new Throwable("Error creating logger", ex);
+        }
+    }
+
+    public static void closeLogger(Logger logger) {
+        for (Handler fh : logger.getHandlers()) {
+            fh.close();
+            logger.removeHandler(fh);
+        }
+    }
+}

src/ru/justblender/bukkit/CustomPayloadFixer.java

@@ -5,23 +5,32 @@
 import com.comphenix.protocol.events.PacketAdapter;
 import com.comphenix.protocol.events.PacketContainer;
 import com.comphenix.protocol.events.PacketEvent;
+import com.comphenix.protocol.reflect.FuzzyReflection;
+import com.comphenix.protocol.reflect.accessors.Accessors;
+import com.comphenix.protocol.reflect.accessors.MethodAccessor;
+import com.comphenix.protocol.reflect.fuzzy.FuzzyMethodContract;
+import com.comphenix.protocol.utility.ByteBufferInputStream;
+import com.comphenix.protocol.utility.MinecraftReflection;
 import com.comphenix.protocol.utility.StreamSerializer;
 import com.comphenix.protocol.wrappers.nbt.NbtCompound;
 import com.comphenix.protocol.wrappers.nbt.NbtFactory;
 import com.comphenix.protocol.wrappers.nbt.NbtList;
 import com.google.common.base.Charsets;
 import io.netty.buffer.ByteBuf;
+import org.apache.commons.lang.Validate;
 import org.bukkit.Bukkit;
 import org.bukkit.entity.Player;
 import org.bukkit.inventory.ItemStack;
 import org.bukkit.plugin.java.JavaPlugin;
+import ru.justblender.PluginLogger.PluginLoggerHelper;
 
-import java.io.ByteArrayInputStream;
+import java.io.DataInput;
 import java.io.DataInputStream;
+import java.io.File;
 import java.io.IOException;
-import java.util.Iterator;
-import java.util.Map;
+import java.util.*;
 import java.util.concurrent.ConcurrentHashMap;
+import java.util.logging.*;
 
 /**
  * ****************************************************************
@@ -40,9 +49,20 @@ public class CustomPayloadFixer extends JavaPlugin {
 
     private String dispatchCommand, kickMessage;
 
+    private static final Set<String> PACKET_NAMES = new HashSet<>(Arrays.asList("MC|BSign", "MC|BEdit", "REGISTER"));
+
+    private Logger logger = null;
+
     @Override
     public void onEnable() {
         saveDefaultConfig();
+        if (getConfig().getBoolean("EnableCustomLog")) {
+            try {
+                logger = PluginLoggerHelper.openLogger(new File(getDataFolder(), "exploits.log"), getConfig().getString("CustomLogFormat"));
+            } catch (Throwable ex) {
+                getLogger().log(Level.SEVERE, ex.getMessage());
+            }
+        }
 
         dispatchCommand = getConfig().getString("dispatchCommand");
         kickMessage = getConfig().getString("kickMessage");
@@ -61,15 +81,29 @@ public void onPacketReceiving(PacketEvent event) {
                     iterator.remove();
             }
         }, 20L, 20L);
+
+        if (logger != null) logger.log(Level.INFO, "Plugin enabled");
     }
 
     @Override
     public void onDisable() {
         ProtocolLibrary.getProtocolManager().removePacketListeners(this);
+        if (logger != null){
+            logger.log(Level.INFO, "Plugin disabled");
+            PluginLoggerHelper.closeLogger(logger);
+        }
     }
 
     private void checkPacket(PacketEvent event) {
         Player player = event.getPlayer();
+        if (player == null) {
+            // Oh! Packet without player o_O. We can't do anything
+            String name = event.getPacket().getStrings().readSafely(0);
+            getLogger().log(Level.SEVERE, "packet ''{0}'' without player ", name);
+            if (logger != null) logger.log(Level.SEVERE, "packet ''{0}'' without player ", name);
+            event.setCancelled(true);
+            return;
+        }
         long lastPacket = PACKET_USAGE.getOrDefault(player, -1L);
 
         // This fucker is already detected as an exploiter
@@ -78,23 +112,23 @@ private void checkPacket(PacketEvent event) {
             return;
         }
 
-        String name = event.getPacket().getStrings().readSafely(0);
-        if (!"MC|BSign".equals(name) && !"MC|BEdit".equals(name) && !"REGISTER".equals(name))
+        String packetName = event.getPacket().getStrings().readSafely(0);
+        if (packetName == null || !PACKET_NAMES.contains(packetName))
             return;
 
         try {
-            if ("REGISTER".equals(name)) {
+            if ("REGISTER".equals(packetName)) {
                 checkChannels(event);
             } else {
                 if (elapsed(lastPacket, 100L)) {
                     PACKET_USAGE.put(player, System.currentTimeMillis());
                 } else {
-                    throw new IOException("Packet flood");
+                    throw new ExploitException("Packet flood");
                 }
 
                 checkNbtTags(event);
             }
-        } catch (Throwable ex) {
+        } catch (ExploitException ex) {
             // Set last packet usage to -2 so we wouldn't mind checking him again
             PACKET_USAGE.put(player, -2L);
 
@@ -107,32 +141,44 @@ private void checkPacket(PacketEvent event) {
             });
 
             getLogger().warning(player.getName() + " tried to exploit CustomPayload: " + ex.getMessage());
+            if (logger != null) logger.log(Level.WARNING, "{0} tried exploit CustomPayload: {1}{2}", new Object[]{player.getName(), ex.getMessage(), ex.itemstackToLogString(" ")});
+            event.setCancelled(true);
+        } catch (Throwable ex) {
+            getLogger().severe(String.format("Failed to check packet '%s' for %s: %s", packetName, player.getName(), ex.getMessage()));
+            if (logger != null) logger.log(Level.SEVERE, String.format("Failed to check packet '%s': ", packetName, player.getName()), ex);
             event.setCancelled(true);
         }
     }
 
-    @SuppressWarnings("deprecation")
-    private void checkNbtTags(PacketEvent event) throws IOException {
+    //@SuppressWarnings("deprecation")
+    private void checkNbtTags(PacketEvent event) throws ExploitException {
         PacketContainer container = event.getPacket();
         ByteBuf buffer = container.getSpecificModifier(ByteBuf.class).read(0).copy();
 
-        byte[] bytes = new byte[buffer.readableBytes()];
-        buffer.readBytes(bytes);
-
-        try (DataInputStream inputStream = new DataInputStream(new ByteArrayInputStream(bytes))) {
-            ItemStack itemStack = StreamSerializer.getDefault().deserializeItemStack(inputStream);
+        try {
+            ItemStack itemStack = null;
+            try {
+                itemStack = deserializeItemStack(buffer);
+            } catch (Throwable ex) {
+                throw new ExploitException("Unable to deserialize ItemStack", ex);
+            }
             if (itemStack == null)
-                throw new IOException("Unable to deserialize ItemStack");
+                throw new ExploitException("Unable to deserialize ItemStack");
 
             NbtCompound root = (NbtCompound) NbtFactory.fromItemTag(itemStack);
-            if (root == null) {
-                throw new IOException("No NBT tag?!");
-            } else if (!root.containsKey("pages")) {
-                throw new IOException("No 'pages' NBT compound was found");
-            } else {
-                NbtList<String> pages = root.getList("pages");
-                if (pages.size() > 50)
-                    throw new IOException("Too much pages");
+            if (root == null)
+                throw new ExploitException("No NBT tag?!", itemStack);
+
+            if (!root.containsKey("pages"))
+                throw new ExploitException("No 'pages' NBT compound was found", itemStack);
+
+            NbtList<String> pages = root.getList("pages");
+            if (pages.size() > 50)
+                throw new ExploitException("Too much pages", itemStack);
+
+            // This is for testing. Take a book, write on first page "CustomPayloadFixer" and either sign it or press done.
+            if (pages.size() > 0 && "CustomPayloadFixer".equalsIgnoreCase(pages.getValue(0)))
+                throw new ExploitException("Testing exploit", itemStack);
 
                 /*
                 Update 1: Here comes the funny part - Minecraft Wiki says that book allows to have only 256 symbols per page,
@@ -147,13 +193,13 @@ private void checkNbtTags(PacketEvent event) throws IOException {
                     if (COLOR_PATTERN.matcher(page).replaceAll("").length() > 257)
                         throw new IOException("A very long page");
                 */
-            }
+
         } finally {
             buffer.release();
         }
     }
 
-    private void checkChannels(PacketEvent event) throws Exception {
+    private void checkChannels(PacketEvent event) throws ExploitException {
         int channelsSize = event.getPlayer().getListeningPluginChannels().size();
 
         PacketContainer container = event.getPacket();
@@ -162,7 +208,7 @@ private void checkChannels(PacketEvent event) throws Exception {
         try {
             for (int i = 0; i < buffer.toString(Charsets.UTF_8).split("\0").length; i++)
                 if (++channelsSize > 124)
-                    throw new IOException("Too much channels");
+                    throw new ExploitException("Too much channels");
         } finally {
             buffer.release();
         }
@@ -171,4 +217,31 @@ private void checkChannels(PacketEvent event) throws Exception {
     private boolean elapsed(long from, long required) {
         return from == -1L || System.currentTimeMillis() - from > required;
     }
+
+    // This rewritten method deserializeItemStack from ProtocolLib
+    // com.comphenix.protocol.utility.StreamSerializer.getDefault().deserializeItemStack(DataInputStream)
+    // Input parameter has changed from DataInputStream to ByteBuf (to reduce code)
+    private static MethodAccessor READ_ITEM_METHOD;
+    private static MethodAccessor WRITE_ITEM_METHOD;
+    public ItemStack deserializeItemStack(ByteBuf buf) throws IOException {
+        Validate.notNull(buf, "input cannot be null!");
+        Object nmsItem = null;
+        if (MinecraftReflection.isUsingNetty()) {
+            if (READ_ITEM_METHOD == null) {
+                READ_ITEM_METHOD = Accessors.getMethodAccessor(FuzzyReflection.fromClass(MinecraftReflection.getPacketDataSerializerClass(), true).getMethodByParameters("readItemStack", MinecraftReflection.getItemStackClass(), new Class[0]));
+            }
+
+            Object serializer = MinecraftReflection.getPacketDataSerializer(buf);
+            nmsItem = READ_ITEM_METHOD.invoke(serializer);
+        } else {
+            if (READ_ITEM_METHOD == null) {
+                READ_ITEM_METHOD = Accessors.getMethodAccessor(FuzzyReflection.fromClass(MinecraftReflection.getPacketClass()).getMethod(FuzzyMethodContract.newBuilder().parameterCount(1).parameterDerivedOf(DataInput.class).returnDerivedOf(MinecraftReflection.getItemStackClass()).build()));
+            }
+
+            DataInputStream input = new DataInputStream(new ByteBufferInputStream(buf.nioBuffer()));
+            nmsItem = READ_ITEM_METHOD.invoke((Object)null, new Object[]{input});
+        }
+
+        return nmsItem != null ? MinecraftReflection.getBukkitItemStack(nmsItem) : null;
+    }
 }