Connection logging support.

src/main/java/com/velocitypowered/proxy/connection/MinecraftConnection.java

@@ -1,19 +1,19 @@
 package com.velocitypowered.proxy.connection;
 
 import com.google.common.base.Preconditions;
-import com.velocitypowered.proxy.Velocity;
 import com.velocitypowered.proxy.protocol.PacketWrapper;
 import com.velocitypowered.proxy.protocol.StateRegistry;
 import com.velocitypowered.proxy.protocol.compression.JavaVelocityCompressor;
 import com.velocitypowered.proxy.protocol.encryption.JavaVelocityCipher;
 import com.velocitypowered.proxy.protocol.encryption.VelocityCipher;
 import com.velocitypowered.proxy.protocol.netty.*;
-import com.velocitypowered.proxy.protocol.packets.SetCompression;
 import io.netty.channel.Channel;
 import io.netty.channel.ChannelFutureListener;
 import io.netty.channel.ChannelHandlerContext;
 import io.netty.channel.ChannelInboundHandlerAdapter;
 import io.netty.util.ReferenceCountUtil;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 
 import javax.crypto.SecretKey;
 import javax.crypto.spec.SecretKeySpec;
@@ -34,11 +34,14 @@ import static com.velocitypowered.network.Connections.MINECRAFT_ENCODER;
  * protocol mechanics.
  */
 public class MinecraftConnection extends ChannelInboundHandlerAdapter {
+    private static final Logger logger = LogManager.getLogger(MinecraftConnection.class);
+
     private final Channel channel;
     private boolean closed;
     private StateRegistry state;
     private MinecraftSessionHandler sessionHandler;
     private int protocolVersion;
+    private MinecraftConnectionAssociation association;
 
     public MinecraftConnection(Channel channel) {
         this.channel = channel;
@@ -51,6 +54,10 @@ public class MinecraftConnection extends ChannelInboundHandlerAdapter {
         if (sessionHandler != null) {
             sessionHandler.connected();
         }
+
+        if (association != null) {
+            logger.info("{} has connected", association);
+        }
     }
 
     @Override
@@ -58,6 +65,10 @@ public class MinecraftConnection extends ChannelInboundHandlerAdapter {
         if (sessionHandler != null) {
             sessionHandler.disconnected();
         }
+
+        if (association != null) {
+            logger.info("{} has disconnected", association);
+        }
     }
 
     @Override
@@ -87,6 +98,12 @@ public class MinecraftConnection extends ChannelInboundHandlerAdapter {
                 sessionHandler.exception(cause);
             }
 
+            if (association != null) {
+                logger.error("{}: exception encountered", association, cause);
+            } else {
+                logger.error("{} encountered an exception", cause);
+            }
+
             closed = true;
             ctx.close();
         }
@@ -187,4 +204,12 @@ public class MinecraftConnection extends ChannelInboundHandlerAdapter {
         channel.pipeline().addBefore(FRAME_DECODER, CIPHER_DECODER, new MinecraftCipherDecoder(decryptionCipher));
         channel.pipeline().addBefore(FRAME_ENCODER, CIPHER_ENCODER, new MinecraftCipherEncoder(encryptionCipher));
     }
+
+    public MinecraftConnectionAssociation getAssociation() {
+        return association;
+    }
+
+    public void setAssociation(MinecraftConnectionAssociation association) {
+        this.association = association;
+    }
 }

src/main/java/com/velocitypowered/proxy/connection/MinecraftConnectionAssociation.java

@@ -0,0 +1,4 @@
+package com.velocitypowered.proxy.connection;
+
+public interface MinecraftConnectionAssociation {
+}

src/main/java/com/velocitypowered/proxy/connection/backend/BackendPlaySessionHandler.java

@@ -8,9 +8,6 @@ import com.velocitypowered.proxy.protocol.packets.Ping;
 import com.velocitypowered.proxy.connection.MinecraftSessionHandler;
 import com.velocitypowered.proxy.protocol.packets.Respawn;
 import io.netty.buffer.ByteBuf;
-import net.kyori.text.TextComponent;
-import net.kyori.text.format.TextColor;
-import net.kyori.text.serializer.ComponentSerializers;
 
 public class BackendPlaySessionHandler implements MinecraftSessionHandler {
     private final ServerConnection connection;
@@ -25,15 +22,8 @@ public class BackendPlaySessionHandler implements MinecraftSessionHandler {
             // Forward onto the server
             connection.getChannel().write(packet);
         } else if (packet instanceof Disconnect) {
-            // The server wants to disconnect us. TODO fallback handling
             Disconnect original = (Disconnect) packet;
-            TextComponent reason = TextComponent.builder()
+            connection.getProxyPlayer().handleConnectionException(connection.getServerInfo(), original);
-                    .content("Disconnected from " + connection.getServerInfo().getName() + ":")
-                    .color(TextColor.RED)
-                    .append(TextComponent.of(" ", TextColor.WHITE))
-                    .append(ComponentSerializers.JSON.deserialize(original.getReason()))
-                    .build();
-            connection.getProxyPlayer().close(reason);
         } else if (packet instanceof JoinGame) {
             ClientPlaySessionHandler playerHandler =
                     (ClientPlaySessionHandler) connection.getProxyPlayer().getConnection().getSessionHandler();

src/main/java/com/velocitypowered/proxy/connection/backend/ServerConnection.java

@@ -1,6 +1,7 @@
 package com.velocitypowered.proxy.connection.backend;
 
 import com.velocitypowered.proxy.config.IPForwardingMode;
+import com.velocitypowered.proxy.connection.MinecraftConnectionAssociation;
 import com.velocitypowered.proxy.protocol.ProtocolConstants;
 import com.velocitypowered.proxy.protocol.netty.MinecraftDecoder;
 import com.velocitypowered.proxy.protocol.netty.MinecraftEncoder;
@@ -26,7 +27,7 @@ import static com.velocitypowered.network.Connections.MINECRAFT_ENCODER;
 import static com.velocitypowered.network.Connections.READ_TIMEOUT;
 import static com.velocitypowered.network.Connections.SERVER_READ_TIMEOUT_SECONDS;
 
-public class ServerConnection {
+public class ServerConnection implements MinecraftConnectionAssociation {
     private final ServerInfo serverInfo;
     private final ConnectedPlayer proxyPlayer;
     private final VelocityServer server;
@@ -53,6 +54,7 @@ public class ServerConnection {
                         MinecraftConnection connection = new MinecraftConnection(ch);
                         connection.setState(StateRegistry.HANDSHAKE);
                         connection.setSessionHandler(new LoginSessionHandler(ServerConnection.this));
+                        connection.setAssociation(ServerConnection.this);
                         ch.pipeline().addLast(HANDLER, connection);
                     }
                 })
@@ -120,4 +122,9 @@ public class ServerConnection {
         channel.close();
         channel = null;
     }
+
+    @Override
+    public String toString() {
+        return "[server connection] " + proxyPlayer.getProfile().getName() + " -> " + serverInfo.getName();
+    }
 }

src/main/java/com/velocitypowered/proxy/connection/client/ConnectedPlayer.java

@@ -1,20 +1,27 @@
 package com.velocitypowered.proxy.connection.client;
 
+import com.velocitypowered.proxy.connection.MinecraftConnectionAssociation;
 import com.velocitypowered.proxy.data.GameProfile;
 import com.velocitypowered.proxy.protocol.packets.Chat;
 import com.velocitypowered.proxy.connection.MinecraftConnection;
 import com.velocitypowered.proxy.connection.backend.ServerConnection;
+import com.velocitypowered.proxy.util.ComponentUtils;
 import com.velocitypowered.proxy.util.ThrowableUtils;
 import com.velocitypowered.proxy.data.ServerInfo;
 import com.velocitypowered.proxy.protocol.packets.Disconnect;
+import net.kyori.text.Component;
 import net.kyori.text.TextComponent;
 import net.kyori.text.format.TextColor;
 import net.kyori.text.serializer.ComponentSerializers;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 
 import java.net.InetSocketAddress;
 import java.util.UUID;
 
-public class ConnectedPlayer {
+public class ConnectedPlayer implements MinecraftConnectionAssociation {
+    private static final Logger logger = LogManager.getLogger(ConnectedPlayer.class);
+
     private final GameProfile profile;
     private final MinecraftConnection connection;
     private ServerConnection connectedServer;
@@ -50,22 +57,39 @@ public class ConnectedPlayer {
 
     public void handleConnectionException(ServerInfo info, Throwable throwable) {
         String error = ThrowableUtils.briefDescription(throwable);
-        Disconnect disconnect = Disconnect.create(TextComponent.of(error, TextColor.RED));
+        String userMessage;
-        handleConnectionException(info, disconnect);
+        if (connectedServer != null && connectedServer.getServerInfo().equals(info)) {
+            logger.error("{}: exception occurred in connection to {}", this, info.getName(), throwable);
+            userMessage = "Exception in server " + info.getName();
+        } else {
+            logger.error("{}: unable to connect to server {}", this, info.getName(), throwable);
+            userMessage = "Exception connecting to server " + info.getName();
+        }
+        handleConnectionException(info, TextComponent.builder()
+                .content(userMessage + ": ")
+                .color(TextColor.RED)
+                .append(TextComponent.of(error))
+                .build());
     }
 
     public void handleConnectionException(ServerInfo info, Disconnect disconnect) {
-        TextComponent component = TextComponent.builder()
+        Component disconnectReason = ComponentSerializers.JSON.deserialize(disconnect.getReason());
-                .content("Exception connecting to server " + info.getName() + ": ")
+        String reason = ComponentUtils.asPlainText(disconnectReason);
-                .color(TextColor.RED)
+        if (connectedServer != null && connectedServer.getServerInfo().equals(info)) {
-                .append(ComponentSerializers.JSON.deserialize(disconnect.getReason()))
+            logger.error("{}: kicked from server {}: {}", this, info.getName(), reason);
-                .build();
-
-        if (connectedServer == null) {
-            // The player isn't yet connected to a server - we should disconnect them.
-            connection.closeWith(Disconnect.create(component));
         } else {
-            connection.write(Chat.create(component));
+            logger.error("{}: disconnected while connecting to {}: {}", this, info.getName(), reason);
+        }
+        handleConnectionException(info, disconnectReason);
+    }
+
+    private void handleConnectionException(ServerInfo info, Component disconnectReason) {
+        if (connectedServer == null || connectedServer.getServerInfo().equals(info)) {
+            // The player isn't yet connected to a server or they are already connected to the server
+            // they're disconnected from.
+            connection.closeWith(Disconnect.create(disconnectReason));
+        } else {
+            connection.write(Chat.create(disconnectReason));
         }
     }
 
@@ -76,4 +100,9 @@ public class ConnectedPlayer {
     public void close(TextComponent reason) {
         connection.closeWith(Disconnect.create(reason));
     }
+
+    @Override
+    public String toString() {
+        return "[connected player] " + getProfile().getName() + " (" + getRemoteAddress() + ")";
+    }
 }

src/main/java/com/velocitypowered/proxy/connection/client/LoginSessionHandler.java

@@ -105,6 +105,8 @@ public class LoginSessionHandler implements MinecraftSessionHandler {
 
         // Initiate a regular connection and move over to it.
         ConnectedPlayer player = new ConnectedPlayer(profile, inbound);
+        logger.info("{} has connected", player);
+        inbound.setAssociation(player);
         ServerInfo info = new ServerInfo("test", new InetSocketAddress("localhost", 25565));
         ServerConnection connection = new ServerConnection(info, player, VelocityServer.getServer());
 

src/main/java/com/velocitypowered/proxy/protocol/packets/Chat.java

@@ -5,7 +5,7 @@ import com.velocitypowered.proxy.protocol.ProtocolConstants;
 import com.velocitypowered.proxy.protocol.MinecraftPacket;
 import com.velocitypowered.proxy.protocol.ProtocolUtils;
 import io.netty.buffer.ByteBuf;
-import net.kyori.text.TextComponent;
+import net.kyori.text.Component;
 import net.kyori.text.serializer.ComponentSerializers;
 
 public class Chat implements MinecraftPacket {
@@ -60,11 +60,11 @@ public class Chat implements MinecraftPacket {
         }
     }
 
-    public static Chat create(TextComponent component) {
+    public static Chat create(Component component) {
         return create(component, (byte) 0);
     }
 
-    public static Chat create(TextComponent component, byte pos) {
+    public static Chat create(Component component, byte pos) {
         Preconditions.checkNotNull(component, "component");
         return new Chat(ComponentSerializers.JSON.serialize(component), pos);
     }

src/main/java/com/velocitypowered/proxy/protocol/packets/Disconnect.java

@@ -5,7 +5,7 @@ import com.velocitypowered.proxy.protocol.ProtocolConstants;
 import com.velocitypowered.proxy.protocol.MinecraftPacket;
 import com.velocitypowered.proxy.protocol.ProtocolUtils;
 import io.netty.buffer.ByteBuf;
-import net.kyori.text.TextComponent;
+import net.kyori.text.Component;
 import net.kyori.text.serializer.ComponentSerializers;
 
 public class Disconnect implements MinecraftPacket {
@@ -43,7 +43,7 @@ public class Disconnect implements MinecraftPacket {
         ProtocolUtils.writeString(buf, reason);
     }
 
-    public static Disconnect create(TextComponent component) {
+    public static Disconnect create(Component component) {
         Preconditions.checkNotNull(component, "component");
         return new Disconnect(ComponentSerializers.JSON.serialize(component));
     }

src/main/java/com/velocitypowered/proxy/util/ComponentUtils.java

@@ -0,0 +1,29 @@
+package com.velocitypowered.proxy.util;
+
+import com.google.common.base.Preconditions;
+import net.kyori.text.Component;
+import net.kyori.text.TextComponent;
+import net.kyori.text.TranslatableComponent;
+
+public enum ComponentUtils {
+    ;
+
+    public static String asPlainText(Component component) {
+        Preconditions.checkNotNull(component, "component");
+        StringBuilder builder = new StringBuilder();
+        appendPlainText(component, builder);
+        return builder.toString();
+    }
+
+    private static void appendPlainText(Component component, StringBuilder builder) {
+        if (component instanceof TextComponent) {
+            builder.append(((TextComponent) component).content());
+        }
+        if (component instanceof TranslatableComponent) {
+            builder.append(((TranslatableComponent) component).key());
+        }
+        for (Component child : component.children()) {
+            appendPlainText(child, builder);
+        }
+    }
+}

src/test/java/com/velocitypowered/proxy/util/ComponentUtilsTest.java

@@ -0,0 +1,31 @@
+package com.velocitypowered.proxy.util;
+
+import net.kyori.text.TextComponent;
+import net.kyori.text.format.TextColor;
+import net.kyori.text.format.TextDecoration;
+import org.junit.jupiter.api.Test;
+
+import static org.junit.jupiter.api.Assertions.*;
+
+class ComponentUtilsTest {
+
+    private static final String SIMPLE_COMPONENT_TEXT = "hello";
+    private static final TextComponent SIMPLE_COMPONENT = TextComponent.of(SIMPLE_COMPONENT_TEXT, TextColor.RED);
+    private static final String COMPLEX_COMPONENT_TEXT = "Hello world! Welcome to Velocity, the Minecraft server proxy built for mass scale.";
+    private static final TextComponent COMPLEX_COMPONENT = TextComponent.builder("Hello world! ")
+            .decoration(TextDecoration.BOLD, true)
+            .append(TextComponent.of("Welcome to "))
+            .decoration(TextDecoration.BOLD, false)
+            .color(TextColor.GREEN)
+            .append(TextComponent.of("Velocity"))
+            .color(TextColor.DARK_AQUA)
+            .append(TextComponent.of(", the Minecraft server proxy built for mass scale."))
+            .resetStyle()
+            .build();
+
+    @Test
+    void asPlainText() {
+        assertEquals(SIMPLE_COMPONENT_TEXT, ComponentUtils.asPlainText(SIMPLE_COMPONENT));
+        assertEquals(COMPLEX_COMPONENT_TEXT, ComponentUtils.asPlainText(COMPLEX_COMPONENT));
+    }
+}