Record http request parameters in log metadata (#2642)

This allows us to search for logs for a given path using a filter like
this:

jsonPayload.httpRequest.requestUrl="/_dr/blah"

TESTED=tested on crash

Author: jianglai

core/src/main/java/google/registry/module/RegistryServlet.java

@@ -14,7 +14,9 @@
 
 package google.registry.module;
 
+import static google.registry.util.GcpJsonFormatter.setCurrentRequest;
 import static google.registry.util.GcpJsonFormatter.setCurrentTraceId;
+import static google.registry.util.GcpJsonFormatter.unsetCurrentRequest;
 import static google.registry.util.RandomStringGenerator.insecureRandomStringGenerator;
 import static google.registry.util.StringGenerator.Alphabets.HEX_DIGITS_ONLY;
 
@@ -67,10 +69,16 @@ public RegistryServlet() {
   @Override
   public void service(HttpServletRequest req, HttpServletResponse rsp) throws IOException {
     setCurrentTraceId(traceId());
+    String requestMethod = req.getMethod();
+    String requestUrl = req.getRequestURI();
+    String userAgent = String.valueOf(req.getHeader("User-Agent"));
+    String protocol = req.getProtocol();
+    setCurrentRequest(requestMethod, requestUrl, userAgent, protocol);
     try {
       super.service(req, rsp);
     } finally {
       setCurrentTraceId(null);
+      unsetCurrentRequest();
     }
   }
 

core/src/main/java/google/registry/tools/RegistryCli.java

@@ -43,7 +43,8 @@
 final class RegistryCli implements CommandRunner {
 
   private static final ImmutableSet<RegistryToolEnvironment> DEFAULT_GKE_ENVIRONMENTS =
-      ImmutableSet.of(RegistryToolEnvironment.ALPHA, RegistryToolEnvironment.QA);
+      ImmutableSet.of(
+          RegistryToolEnvironment.ALPHA, RegistryToolEnvironment.CRASH, RegistryToolEnvironment.QA);
 
   // The environment parameter is parsed twice: once here, and once with {@link
   // RegistryToolEnvironment#parseFromArgs} in the {@link RegistryTool#main} function.

util/src/main/java/google/registry/util/GcpJsonFormatter.java

@@ -26,6 +26,7 @@
 import java.util.logging.Formatter;
 import java.util.logging.Level;
 import java.util.logging.LogRecord;
+import javax.annotation.Nullable;
 
 /**
  * JUL formatter that formats log messages in a single-line JSON that Stackdriver logging can parse.
@@ -54,6 +55,9 @@ public class GcpJsonFormatter extends Formatter {
   /** JSON field that stores the trace associated with the log entry, if any. */
   private static final String TRACE = "logging.googleapis.com/trace";
 
+  /** JSON field that stores the parameters of the current request, if any. */
+  private static final String HTTP_REQUEST = "httRequest";
+
   /** JSON field that contains the content, this will show up as the main entry in a log. */
   private static final String MESSAGE = "message";
 
@@ -77,19 +81,36 @@ public class GcpJsonFormatter extends Formatter {
 
   private static final ThreadLocal<String> traceId = new ThreadLocal<>();
 
+  private static final ThreadLocal<HttpRequest> request = new ThreadLocal<>();
+
   /**
    * Set the Trace ID associated with any logging done by the current thread.
    *
    * @param id The traceID, in the form projects/[PROJECT_ID]/traces/[TRACE_ID]
    */
-  public static void setCurrentTraceId(String id) {
+  public static void setCurrentTraceId(@Nullable String id) {
     if (id == null) {
       traceId.remove();
     } else {
       traceId.set(id);
     }
   }
 
+  /**
+   * Record the parameters of the current request.
+   *
+   * @see <a
+   *     href="https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#httprequest">HttpRequest</a>
+   */
+  public static void setCurrentRequest(
+      String requestMethod, String requestUrl, String userAgent, String protocol) {
+    request.set(new HttpRequest(requestMethod, requestUrl, userAgent, protocol));
+  }
+
+  public static void unsetCurrentRequest() {
+    request.remove();
+  }
+
   /**
    * Get the Trace ID associated with any logging done by the current thread.
    *
@@ -156,6 +177,9 @@ public String format(LogRecord record) {
     if (traceId.get() != null) {
       json.put(TRACE, traceId.get());
     }
+    if (request.get() != null) {
+      json.put(HTTP_REQUEST, request.get());
+    }
     // This trailing newline is required for the proxy because otherwise multiple logs might be
     // sent to Stackdriver together (due to the async nature of the proxy), and not parsed
     // correctly.
@@ -181,4 +205,7 @@ private static String severityFor(Level level) {
       default -> "DEFAULT";
     };
   }
+
+  private record HttpRequest(
+      String requestMethod, String requestUrl, String userAgent, String protocol) {}
 }

util/src/test/java/google/registry/util/GcpJsonFormatterTest.java

@@ -45,8 +45,8 @@ class GcpJsonFormatterTest {
 
   private static final String LOG_TEMPLATE =
       """
-      {"severity":"@@SEVERITY@@","logging.googleapis.com/sourceLocation":{"file":"GcpJsonFormatterTest.java","line":"@@LINE@@","function":"google.registry.util.GcpJsonFormatterTest.@@FUNCTION@@"},"message":"@@MESSAGE@@"}
-      """;
+{"severity":"@@SEVERITY@@","logging.googleapis.com/sourceLocation":{"file":"GcpJsonFormatterTest.java","line":"@@LINE@@","function":"google.registry.util.GcpJsonFormatterTest.@@FUNCTION@@"},"message":"@@MESSAGE@@"}
+""";
 
   private static String makeJson(String severity, int line, String function, String message) {
     return LOG_TEMPLATE
@@ -71,14 +71,15 @@ void beforeEach() {
   void afterEach() {
     jdkLogger.removeHandler(handler);
     GcpJsonFormatter.setCurrentTraceId(null);
+    GcpJsonFormatter.unsetCurrentRequest();
   }
 
   @Test
   void testSuccess() {
     logger.atInfo().log("Something I have to say");
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
-    assertThat(output).isEqualTo(makeJson("INFO", 78, "testSuccess", "Something I have to say"));
+    assertThat(output).isEqualTo(makeJson("INFO", 79, "testSuccess", "Something I have to say"));
   }
 
   @Test
@@ -87,21 +88,37 @@ void testSuccess_traceId() {
     logger.atInfo().log("Something I have to say");
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
-    String expected = makeJson("INFO", 87, "testSuccess_traceId", "Something I have to say");
+    String expected = makeJson("INFO", 88, "testSuccess_traceId", "Something I have to say");
     // Remove the last two characters (}, \n) from the template and add the trace ID.
     expected =
         expected.substring(0, expected.length() - 2)
             + ",\"logging.googleapis.com/trace\":\"trace_id\"}\n";
     assertThat(output).isEqualTo(expected);
   }
 
+  @Test
+  void testSuccess_currentRequest() {
+    GcpJsonFormatter.setCurrentRequest("GET", "/path", "My-Agent", "HTTP/1.1");
+    logger.atInfo().log("Something I have to say");
+    handler.close();
+    String output = ostream.toString(StandardCharsets.US_ASCII);
+    String expected =
+        makeJson("INFO", 102, "testSuccess_currentRequest", "Something I have to say");
+    // Remove the last two characters (}, \n) from the template and add the request.
+    expected =
+        expected.substring(0, expected.length() - 2)
+            + ",\"httRequest\":{\"requestMethod\":\"GET\",\"requestUrl\":\"/path\""
+            + ",\"userAgent\":\"My-Agent\",\"protocol\":\"HTTP/1.1\"}}\n";
+    assertThat(output).isEqualTo(expected);
+  }
+
   @Test
   void testSuccess_logLevel() {
     logger.atSevere().log("Something went terribly wrong");
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
     assertThat(output)
-        .isEqualTo(makeJson("ERROR", 100, "testSuccess_logLevel", "Something went terribly wrong"));
+        .isEqualTo(makeJson("ERROR", 117, "testSuccess_logLevel", "Something went terribly wrong"));
   }
 
   @Test
@@ -110,7 +127,7 @@ void testSuccess_withCause() {
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
     String prefix =
-        makeJson("ERROR", 109, "testSuccess_withCause", "Something went terribly wrong");
+        makeJson("ERROR", 126, "testSuccess_withCause", "Something went terribly wrong");
     // Remove the last two characters (}, \n) from the template as the actual output contains
     // the full stack trace.
     prefix = prefix.substring(0, prefix.length() - 2);
@@ -124,7 +141,7 @@ void testSuccess_withStackTrace() {
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
     String prefix =
-        makeJson("ERROR", 123, "testSuccess_withStackTrace", "Something is worth checking");
+        makeJson("ERROR", 140, "testSuccess_withStackTrace", "Something is worth checking");
     // Remove the last three characters (}, \n) from the template as the actual output contains
     // the full stack trace.
     prefix = prefix.substring(0, prefix.length() - 2);
@@ -150,7 +167,7 @@ void testSuccess_timeLimiter() throws Exception {
     TimeLimiter.create().callWithTimeout(this::logSomething, 1, TimeUnit.SECONDS);
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
-    assertThat(output).isEqualTo(makeJson("INFO", 171, "logSomething", "Something I have to say"));
+    assertThat(output).isEqualTo(makeJson("INFO", 188, "logSomething", "Something I have to say"));
   }
 
   @Test
@@ -159,7 +176,7 @@ void testSuccess_timeLimiter_traceId() throws Exception {
     TimeLimiter.create().callWithTimeout(this::logSomething, 1, TimeUnit.SECONDS);
     handler.close();
     String output = ostream.toString(StandardCharsets.US_ASCII);
-    String expected = makeJson("INFO", 171, "logSomething", "Something I have to say");
+    String expected = makeJson("INFO", 188, "logSomething", "Something I have to say");
     // Remove the last two characters (}, \n) from the template and add the trace ID.
     expected =
         expected.substring(0, expected.length() - 2)