Add logging to WhoisReader

Logging will make it easier to troubleshoot WhoisServer exceptions.

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

java/google/registry/whois/WhoisReader.java

@@ -26,6 +26,7 @@ import com.google.common.io.CharStreams;
 import com.google.common.net.InetAddresses;
 import com.google.common.net.InternetDomainName;
 import google.registry.config.RegistryConfig.Config;
+import google.registry.util.FormattingLogger;
 import java.io.IOException;
 import java.io.Reader;
 import java.util.ArrayList;
@@ -62,6 +63,8 @@ import org.joda.time.DateTime;
  */
 class WhoisReader {
 
+  static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass();
+
   /**
    * These are strings that will always trigger a specific query type when they are sent at
    * the beginning of a command.
@@ -111,6 +114,7 @@ class WhoisReader {
 
       // Try to parse the argument as a domain name.
       try {
+        logger.infofmt("Attempting domain lookup command using domain name %s", tokens.get(1));
         return commandFactory.domainLookup(InternetDomainName.from(
             canonicalizeDomainName(tokens.get(1))));
       } catch (IllegalArgumentException iae) {
@@ -129,6 +133,8 @@ class WhoisReader {
 
       // Try to parse the argument as an IP address.
       try {
+        logger.infofmt(
+            "Attempting nameserver lookup command using %s as an IP address", tokens.get(1));
         return commandFactory.nameserverLookupByIp(InetAddresses.forString(tokens.get(1)));
       } catch (IllegalArgumentException iae) {
         // Silently ignore this exception.
@@ -136,6 +142,8 @@ class WhoisReader {
 
       // Try to parse the argument as a host name.
       try {
+        logger.infofmt(
+            "Attempting nameserver lookup command using %s as a hostname", tokens.get(1));
         return commandFactory.nameserverLookupByHost(InternetDomainName.from(
             canonicalizeDomainName(tokens.get(1))));
       } catch (IllegalArgumentException iae) {
@@ -153,13 +161,17 @@ class WhoisReader {
         throw new WhoisException(now, SC_BAD_REQUEST, String.format(
             "Too few arguments to '%s' command.", REGISTRAR_LOOKUP_COMMAND));
       }
-      return commandFactory.registrarLookup(Joiner.on(' ').join(tokens.subList(1, tokens.size())));
+      String registrarLookupArgument = Joiner.on(' ').join(tokens.subList(1, tokens.size()));
+      logger.infofmt(
+          "Attempting registrar lookup command using registrar %s", registrarLookupArgument);
+      return commandFactory.registrarLookup(registrarLookupArgument);
     }
 
     // If we have a single token, then try to interpret that in various ways.
     if (tokens.size() == 1) {
       // Try to parse it as an IP address. If successful, then this is a lookup on a nameserver.
       try {
+        logger.infofmt("Attempting nameserver lookup using %s as an IP address", arg1);
         return commandFactory.nameserverLookupByIp(InetAddresses.forString(arg1));
       } catch (IllegalArgumentException iae) {
         // Silently ignore this exception.
@@ -174,16 +186,19 @@ class WhoisReader {
         Optional<InternetDomainName> tld = findTldForName(targetName);
         if (!tld.isPresent()) {
           // This target is not under any configured TLD, so just try it as a registrar name.
+          logger.infofmt("Attempting registrar lookup using %s as a registrar", arg1);
           return new RegistrarLookupCommand(arg1);
         }
 
         // If the target is exactly one level above the TLD, then this is a second level domain
         // (SLD) and we should do a domain lookup on it.
         if (targetName.parent().equals(tld.get())) {
+          logger.infofmt("Attempting domain lookup using %s as a domain name", targetName);
           return commandFactory.domainLookup(targetName);
         }
 
         // The target is more than one level above the TLD, so we'll assume it's a nameserver.
+        logger.infofmt("Attempting nameserver lookup using %s as a hostname", targetName);
         return commandFactory.nameserverLookupByHost(targetName);
       } catch (IllegalArgumentException e) {
         // Silently ignore this exception.
@@ -194,7 +209,10 @@ class WhoisReader {
 
     // The only case left is that there are multiple tokens with no particular command given. We'll
     // assume this is a registrar lookup, since there's really nothing else it could be.
-    return commandFactory.registrarLookup(Joiner.on(' ').join(tokens));
+    String registrarLookupArgument = Joiner.on(' ').join(tokens);
+    logger.infofmt(
+        "Attempting registrar lookup employing %s as a registrar", registrarLookupArgument);
+    return commandFactory.registrarLookup(registrarLookupArgument);
   }
 
   /** Returns an ArrayList containing the contents of the String array minus any empty strings. */

javatests/google/registry/whois/BUILD

@@ -23,6 +23,7 @@ java_library(
         "@com_google_appengine_testing",
         "@com_google_dagger",
         "@com_google_guava",
+        "@com_google_guava_testlib",
         "@com_google_truth",
         "@javax_servlet_api",
         "@joda_time",

javatests/google/registry/whois/WhoisReaderTest.java

@@ -16,11 +16,14 @@ package google.registry.whois;
 
 import static com.google.common.truth.Truth.assertThat;
 import static google.registry.testing.DatastoreHelper.createTlds;
+import static google.registry.testing.LogsSubject.assertAboutLogs;
 
+import com.google.common.testing.TestLogHandler;
 import google.registry.testing.AppEngineRule;
 import google.registry.testing.ExceptionRule;
 import google.registry.testing.FakeClock;
 import java.io.StringReader;
+import java.util.logging.Level;
 import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
@@ -36,13 +39,15 @@ public class WhoisReaderTest {
   @Rule public final ExceptionRule thrown = new ExceptionRule();
 
   private final FakeClock clock = new FakeClock();
+  private final TestLogHandler testLogHandler = new TestLogHandler();
 
   @Before
   public void init() {
     createTlds("tld", "xn--kgbechtv", "1.test");
+    WhoisReader.logger.addHandler(testLogHandler);
   }
 
-  @SuppressWarnings("unchecked") // XXX: Generic abuse ftw.
+  @SuppressWarnings("TypeParameterUnusedInFormals") // XXX: Generic abuse ftw.
   <T> T readCommand(String commandStr) throws Exception {
     return (T)
         new WhoisReader(new WhoisCommandFactory())
@@ -334,4 +339,93 @@ public class WhoisReaderTest {
     this.<RegistrarLookupCommand>readCommand("test");
     this.<RegistrarLookupCommand>readCommand("tld");
   }
+
+  @Test
+  public void testNoArgs() throws Exception {
+    thrown.expect(WhoisException.class);
+    readCommand("");
+  }
+
+  @Test
+  public void testLogsDomainLookupCommand() throws Exception {
+    readCommand("domain example.tld");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting domain lookup command using domain name example.tld");
+  }
+
+  @Test
+  public void testLogsNameserverLookupCommandWithIpAddress() throws Exception {
+    readCommand("nameserver 43.34.12.213");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting nameserver lookup command using 43.34.12.213 as an IP address");
+  }
+
+  @Test
+  public void testLogsNameserverLookupCommandWithHostname() throws Exception {
+    readCommand("nameserver ns.example.tld");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting nameserver lookup command using ns.example.tld as a hostname");
+  }
+
+  @Test
+  public void testLogsRegistrarLookupCommand() throws Exception {
+    readCommand("registrar Example Registrar, Inc.");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO,
+            "Attempting registrar lookup command using registrar Example Registrar, Inc.");
+  }
+
+  @Test
+  public void testLogsSingleArgumentNameserverLookupUsingIpAddress() throws Exception {
+    readCommand("43.34.12.213");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting nameserver lookup using 43.34.12.213 as an IP address");
+  }
+
+  @Test
+  public void testLogsSingleArgumentRegistrarLookup() throws Exception {
+    readCommand("test");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting registrar lookup using test as a registrar");
+  }
+
+  @Test
+  public void testLogsSingleArgumentDomainLookup() throws Exception {
+    readCommand("example.tld");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting domain lookup using example.tld as a domain name");
+  }
+
+  @Test
+  public void testLogsSingleArgumentNameserverLookupUsingHostname() throws Exception {
+    readCommand("ns.example.tld");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO, "Attempting nameserver lookup using ns.example.tld as a hostname");
+  }
+
+  @Test
+  public void testLogsMultipleArgumentsButNoParticularCommand() throws Exception {
+    readCommand("Example Registrar, Inc.");
+    assertAboutLogs()
+        .that(testLogHandler)
+        .hasLogAtLevelWithMessage(
+            Level.INFO,
+            "Attempting registrar lookup employing Example Registrar, Inc. as a registrar");
+  }
 }