Refine logs in the proxy

[1] All logs should contain a reference to the channel so that it is easy to search for logs about a specific channel.

[2] EPP ssl handshake failure should be logged at warning. It is mostly the client that failed to complete the handshake, for example by sending bad cert, or not sending cert, or not using the correct SSL version. We should not lot it at error and spam the log.

[3] When the EPP response is not 200, we should not log at error because it means that the GAE app responded successfully. For example when datastore contention occurs, app engine responds with a non-200 status and logs at warning. The proxy should not at a higher level than app engine itself.

[4] Timeout is a non-fatal error that should be logged at warning.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=207562299

java/google/registry/proxy/handler/EppServiceHandler.java

@@ -118,7 +118,7 @@ public class EppServiceHandler extends HttpsRelayServiceHandler {
                         "epp", sslClientCertificateHash, ctx.channel());
                     channelRead(ctx, Unpooled.wrappedBuffer(helloBytes));
                   } else {
-                    logger.atSevere().withCause(promise.cause()).log(
+                    logger.atWarning().withCause(promise.cause()).log(
                         "Cannot finish handshake for channel %s", ctx.channel());
                     ChannelFuture unusedFuture = ctx.close();
                   }

java/google/registry/proxy/handler/HttpsRelayServiceHandler.java

@@ -34,6 +34,7 @@ import io.netty.handler.codec.http.HttpVersion;
 import io.netty.handler.codec.http.cookie.ClientCookieDecoder;
 import io.netty.handler.codec.http.cookie.ClientCookieEncoder;
 import io.netty.handler.codec.http.cookie.Cookie;
+import io.netty.handler.timeout.ReadTimeoutException;
 import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Map;
@@ -152,8 +153,9 @@ abstract class HttpsRelayServiceHandler extends ByteToMessageCodec<FullHttpRespo
       throws Exception {
     checkArgument(
         response.status().equals(HttpResponseStatus.OK),
-        "Cannot relay HTTP response status \"%s\"\n%s",
+        "Cannot relay HTTP response status \"%s\"in channel %s:\n%s",
         response.status(),
+        ctx.channel(),
         response.content().toString(UTF_8));
     saveCookies(response);
     byteBuf.writeBytes(encodeFullHttpResponse(response));
@@ -162,8 +164,17 @@ abstract class HttpsRelayServiceHandler extends ByteToMessageCodec<FullHttpRespo
   /** Terminates connection upon inbound exception. */
   @Override
   public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
-    logger.atSevere().withCause(cause).log(
+    // ReadTimeoutException is non fatal as the client times out due to inactivity.
-        "Inbound exception caught for channel %s", ctx.channel());
+    // IllegalArgumentException is thrown by the checkArgument in the #encode command, it just means
+    // that GAE returns a non-200 response and the connection should be killed. The request is still
+    // processed by GAE, so this is not an unexpected behavior.
+    if (cause instanceof ReadTimeoutException || cause instanceof IllegalArgumentException) {
+      logger.atWarning().withCause(cause).log(
+          "Inbound exception caught for channel %s", ctx.channel());
+    } else {
+      logger.atSevere().withCause(cause).log(
+          "Inbound exception caught for channel %s", ctx.channel());
+    }
     ChannelFuture unusedFuture = ctx.close();
   }
 

java/google/registry/proxy/handler/ProxyProtocolHandler.java

@@ -75,23 +75,27 @@ public class ProxyProtocolHandler extends ByteToMessageDecoder {
       String remoteIP;
       if (proxyHeader != null) {
         logger.atFine().log("PROXIED CONNECTION: %s", ctx.channel());
-        logger.atFine().log("PROXY HEADER: %s", proxyHeader);
+        logger.atFine().log("PROXY HEADER for channel %s: %s", ctx.channel(), proxyHeader);
         String[] headerArray = proxyHeader.split(" ", -1);
         if (headerArray.length == 6) {
           remoteIP = headerArray[2];
-          logger.atFine().log("Header parsed, using %s as remote IP.", remoteIP);
+          logger.atFine().log(
+              "Header parsed, using %s as remote IP for channel %s", remoteIP, ctx.channel());
         } else {
-          logger.atFine().log("Cannot parse the header, using source IP as a last resort.");
+          logger.atFine().log(
+              "Cannot parse the header, using source IP as remote IP for channel %s",
+              ctx.channel());
           remoteIP = getSourceIP(ctx);
         }
       } else {
-        logger.atFine().log("No header present, using source IP directly.");
+        logger.atFine().log(
+            "No header present, using source IP directly for channel %s", ctx.channel());
         remoteIP = getSourceIP(ctx);
       }
       if (remoteIP != null) {
         ctx.channel().attr(REMOTE_ADDRESS_KEY).set(remoteIP);
       } else {
-        logger.atWarning().log("Not able to obtain remote IP for %s", ctx.channel());
+        logger.atWarning().log("Not able to obtain remote IP for channel %s", ctx.channel());
       }
       // ByteToMessageDecoder automatically flushes unread bytes in the ByteBuf to the next handler
       // when itself is being removed.