diff --git a/core/src/main/java/google/registry/module/RegistryServlet.java b/core/src/main/java/google/registry/module/RegistryServlet.java index eeb7cd1a1..9ffe1c3fb 100644 --- a/core/src/main/java/google/registry/module/RegistryServlet.java +++ b/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 class RegistryServlet extends ServletBase { @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(); } } diff --git a/core/src/main/java/google/registry/tools/RegistryCli.java b/core/src/main/java/google/registry/tools/RegistryCli.java index 0228b308e..c25afd407 100644 --- a/core/src/main/java/google/registry/tools/RegistryCli.java +++ b/core/src/main/java/google/registry/tools/RegistryCli.java @@ -43,7 +43,8 @@ import org.postgresql.util.PSQLException; final class RegistryCli implements CommandRunner { private static final ImmutableSet 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. diff --git a/util/src/main/java/google/registry/util/GcpJsonFormatter.java b/util/src/main/java/google/registry/util/GcpJsonFormatter.java index 065022b8b..8c6a80b64 100644 --- a/util/src/main/java/google/registry/util/GcpJsonFormatter.java +++ b/util/src/main/java/google/registry/util/GcpJsonFormatter.java @@ -26,6 +26,7 @@ import java.util.Optional; 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,12 +81,14 @@ public class GcpJsonFormatter extends Formatter { private static final ThreadLocal traceId = new ThreadLocal<>(); + private static final ThreadLocal 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 { @@ -90,6 +96,21 @@ public class GcpJsonFormatter extends Formatter { } } + /** + * Record the parameters of the current request. + * + * @see HttpRequest + */ + 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 class GcpJsonFormatter extends Formatter { 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 @@ public class GcpJsonFormatter extends Formatter { default -> "DEFAULT"; }; } + + private record HttpRequest( + String requestMethod, String requestUrl, String userAgent, String protocol) {} } diff --git a/util/src/test/java/google/registry/util/GcpJsonFormatterTest.java b/util/src/test/java/google/registry/util/GcpJsonFormatterTest.java index 45d49f22a..acf3c1bc8 100644 --- a/util/src/test/java/google/registry/util/GcpJsonFormatterTest.java +++ b/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,6 +71,7 @@ class GcpJsonFormatterTest { void afterEach() { jdkLogger.removeHandler(handler); GcpJsonFormatter.setCurrentTraceId(null); + GcpJsonFormatter.unsetCurrentRequest(); } @Test @@ -78,7 +79,7 @@ class GcpJsonFormatterTest { 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,7 +88,7 @@ class GcpJsonFormatterTest { 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) @@ -95,13 +96,29 @@ class GcpJsonFormatterTest { 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 @@ class GcpJsonFormatterTest { 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 @@ class GcpJsonFormatterTest { 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 @@ class GcpJsonFormatterTest { 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 @@ class GcpJsonFormatterTest { 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)