Make logging work correctly on Jetty (#2442)

common/gradle.lockfile

@@ -24,7 +24,7 @@ com.google.guava:failureaccess:1.0.2=compileClasspath,deploy_jar,runtimeClasspat
 com.google.guava:guava-parent:32.1.1-jre=annotationProcessor,errorprone,testAnnotationProcessor,testingAnnotationProcessor
 com.google.guava:guava:31.0.1-jre=checkstyle
 com.google.guava:guava:32.1.1-jre=annotationProcessor,errorprone,testAnnotationProcessor,testingAnnotationProcessor
-com.google.guava:guava:33.1.0-jre=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath,testing,testingCompileClasspath
+com.google.guava:guava:33.2.0-jre=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath,testing,testingCompileClasspath
 com.google.guava:listenablefuture:9999.0-empty-to-avoid-conflict-with-guava=checkstyle,compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath,testing,testingCompileClasspath
 com.google.inject:guice:5.1.0=annotationProcessor,errorprone,testAnnotationProcessor,testingAnnotationProcessor
 com.google.j2objc:j2objc-annotations:1.3=checkstyle

core/build.gradle

@@ -159,7 +159,6 @@ dependencies {
   implementation deps['com.google.cloud.bigdataoss:util']
   implementation deps['com.google.cloud.sql:jdbc-socket-factory-core']
   runtimeOnly deps['com.google.cloud.sql:postgres-socket-factory']
-  implementation deps['com.google.cloud:google-cloud-logging']
   implementation deps['com.google.cloud:google-cloud-secretmanager']
   implementation deps['com.google.code.gson:gson']
   implementation deps['com.google.auto.service:auto-service-annotations']

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

@@ -14,17 +14,23 @@
 
 package google.registry.module;
 
-import static com.google.cloud.logging.TraceLoggingEnhancer.setCurrentTraceId;
+import static google.registry.util.GcpJsonFormatter.setCurrentTraceId;
 import static google.registry.util.RandomStringGenerator.insecureRandomStringGenerator;
 import static google.registry.util.StringGenerator.Alphabets.HEX_DIGITS_ONLY;
 
 import com.google.monitoring.metrics.MetricReporter;
 import dagger.Lazy;
 import google.registry.request.RequestHandler;
+import google.registry.util.GcpJsonFormatter;
+import google.registry.util.JdkLoggerConfig;
 import google.registry.util.RandomStringGenerator;
 import jakarta.servlet.http.HttpServletRequest;
 import jakarta.servlet.http.HttpServletResponse;
 import java.io.IOException;
+import java.util.Arrays;
+import java.util.logging.ConsoleHandler;
+import java.util.logging.Handler;
+import java.util.logging.Level;
 
 /** Servlet that handles all requests. */
 public class RegistryServlet extends ServletBase {
@@ -42,6 +48,17 @@ public class RegistryServlet extends ServletBase {
 
   private final String projectId;
 
+  static {
+    // Remove all other handlers on the root logger to avoid double logging.
+    JdkLoggerConfig rootLoggerConfig = JdkLoggerConfig.getConfig("");
+    Arrays.asList(rootLoggerConfig.getHandlers()).forEach(rootLoggerConfig::removeHandler);
+
+    Handler rootHandler = new ConsoleHandler();
+    rootHandler.setLevel(Level.INFO);
+    rootHandler.setFormatter(new GcpJsonFormatter());
+    rootLoggerConfig.addHandler(rootHandler);
+  }
+
   public RegistryServlet() {
     super(requestHandler, metricReporter);
     this.projectId = component.projectId();

core/src/test/java/google/registry/beam/BeamUtilsTest.java

@@ -18,6 +18,7 @@
 import static org.junit.jupiter.api.Assertions.assertThrows;
 
 import com.google.common.collect.ImmutableList;
+import org.apache.avro.AvroRuntimeException;
 import org.apache.avro.Schema;
 import org.apache.avro.generic.GenericData;
 import org.apache.avro.generic.GenericRecord;
@@ -55,10 +56,13 @@ void testExtractField_fieldExists_returnsExpectedStringValues() {
   }
 
   @Test
-  void testExtractField_fieldDoesntExist_returnsNull() {
+  void testExtractField_fieldDoesntExist_throwsException() {
     schemaAndRecord.getRecord().put("aFloat", null);
-    assertThat(BeamUtils.extractField(schemaAndRecord.getRecord(), "aFloat")).isEqualTo("null");
-    assertThat(BeamUtils.extractField(schemaAndRecord.getRecord(), "missing")).isEqualTo("null");
+    AvroRuntimeException expected =
+        assertThrows(
+            AvroRuntimeException.class,
+            () -> BeamUtils.extractField(schemaAndRecord.getRecord(), "missing"));
+    assertThat(expected).hasMessageThat().isEqualTo("Not a valid schema field: missing");
   }
 
   @Test
@@ -68,16 +72,12 @@ void testCheckFieldsNotNull_noExceptionIfAllPresent() {
 
   @Test
   void testCheckFieldsNotNull_fieldMissing_throwsException() {
-    IllegalStateException expected =
+    AvroRuntimeException expected =
         assertThrows(
-            IllegalStateException.class,
+            AvroRuntimeException.class,
             () ->
                 BeamUtils.checkFieldsNotNull(
                     ImmutableList.of("aString", "aFloat", "notAField"), schemaAndRecord));
-    assertThat(expected)
-        .hasMessageThat()
-        .isEqualTo(
-            "Read unexpected null value for field(s) notAField for record "
-                + "{\"aString\": \"hello world\", \"aFloat\": 2.54}");
+    assertThat(expected).hasMessageThat().isEqualTo("Not a valid schema field: notAField");
   }
 }

db/gradle.lockfile

@@ -50,7 +50,7 @@ com.google.guava:guava-parent:32.1.1-jre=annotationProcessor,errorprone,testAnno
 com.google.guava:guava:31.0.1-jre=checkstyle
 com.google.guava:guava:32.1.1-jre=annotationProcessor,errorprone,testAnnotationProcessor
 com.google.guava:guava:33.1.0-android=deploy_jar,runtimeClasspath,testRuntimeClasspath
-com.google.guava:guava:33.1.0-jre=testCompileClasspath
+com.google.guava:guava:33.2.0-jre=testCompileClasspath
 com.google.guava:listenablefuture:9999.0-empty-to-avoid-conflict-with-guava=checkstyle,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
 com.google.http-client:google-http-client-apache-v2:1.44.1=deploy_jar,runtimeClasspath,testRuntimeClasspath
 com.google.http-client:google-http-client-gson:1.44.1=deploy_jar,runtimeClasspath,testRuntimeClasspath
@@ -91,8 +91,8 @@ org.checkerframework:checker-compat-qual:2.5.3=testCompileClasspath,testRuntimeC
 org.checkerframework:checker-qual:3.12.0=checkstyle
 org.checkerframework:checker-qual:3.33.0=annotationProcessor,errorprone,testAnnotationProcessor
 org.checkerframework:checker-qual:3.42.0=deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
-org.flywaydb:flyway-core:10.12.0=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
-org.flywaydb:flyway-database-postgresql:10.12.0=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
+org.flywaydb:flyway-core:10.13.0=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
+org.flywaydb:flyway-database-postgresql:10.13.0=compileClasspath,deploy_jar,runtimeClasspath,testCompileClasspath,testRuntimeClasspath
 org.hamcrest:hamcrest-core:1.3=testCompileClasspath,testRuntimeClasspath
 org.jacoco:org.jacoco.agent:0.8.11=jacocoAgent,jacocoAnt
 org.jacoco:org.jacoco.ant:0.8.11=jacocoAnt
@@ -119,9 +119,9 @@ org.reflections:reflections:0.10.2=checkstyle
 org.rnorth.duct-tape:duct-tape:1.0.8=testCompileClasspath,testRuntimeClasspath
 org.slf4j:slf4j-api:1.7.36=testCompileClasspath
 org.slf4j:slf4j-api:2.0.13=deploy_jar,runtimeClasspath,testRuntimeClasspath
-org.testcontainers:database-commons:1.19.7=testCompileClasspath,testRuntimeClasspath
-org.testcontainers:jdbc:1.19.7=testCompileClasspath,testRuntimeClasspath
-org.testcontainers:junit-jupiter:1.19.7=testCompileClasspath,testRuntimeClasspath
-org.testcontainers:postgresql:1.19.7=testCompileClasspath,testRuntimeClasspath
-org.testcontainers:testcontainers:1.19.7=testCompileClasspath,testRuntimeClasspath
+org.testcontainers:database-commons:1.19.8=testCompileClasspath,testRuntimeClasspath
+org.testcontainers:jdbc:1.19.8=testCompileClasspath,testRuntimeClasspath
+org.testcontainers:junit-jupiter:1.19.8=testCompileClasspath,testRuntimeClasspath
+org.testcontainers:postgresql:1.19.8=testCompileClasspath,testRuntimeClasspath
+org.testcontainers:testcontainers:1.19.8=testCompileClasspath,testRuntimeClasspath
 empty=implementationApi,schema

dependencies.gradle

@@ -139,7 +139,6 @@ ext {
       'com.google.cloud.sql:postgres-socket-factory:[1.2.1,)',
       'com.google.cloud:google-cloud-core-http:[1.94.3,)',
       'com.google.cloud:google-cloud-core:[1.94.3,)',
-      'com.google.cloud:google-cloud-logging:[3.16.3,)',
       'com.google.cloud:google-cloud-nio:[0.123.4,)',
       'com.google.cloud:google-cloud-secretmanager:[1.4.0,)',
       'com.google.cloud:google-cloud-storage:[2.26.0,)',

jetty/build.gradle

@@ -27,35 +27,13 @@ war {
     dependsOn(tasks.named('copyJettyBase'))
 }
 
-test {
-    filter {
-        // As the only test class in this project, this must be in the 'test'
-        // task. If more tests are added, this class along with the system
-        // property definition below, should be moved to a dedicated task.
-        includeTestsMatching "google.registry.jetty.LoggingPropertiesTest.*"
-    }
-
-    systemProperty 'java.util.logging.config.file', "${projectDir}/logging.properties"
-}
-
 tasks.named('compileTestJava') {
     // Gradle insists on this execution dependency.
     dependsOn(tasks.named('copyJettyBase'))
 }
 
 dependencies {
-    def deps = rootProject.dependencyMap
     implementation project(':core')
-
-    testRuntimeOnly project(':util')
-    testImplementation deps['com.google.cloud:google-cloud-logging']
-    testImplementation deps['com.google.code.gson:gson']
-    testImplementation deps['com.google.flogger:flogger']
-    testImplementation deps['com.google.guava:guava']
-    testImplementation deps['com.google.truth:truth']
-
-    testImplementation deps['org.junit.jupiter:junit-jupiter-api']
-    testImplementation deps['org.junit.jupiter:junit-jupiter-engine']
 }
 
 tasks.register('copyConsole', Copy) {
@@ -83,6 +61,7 @@ tasks.register('tagNomulusImage', Exec) {
 
 tasks.register('pushNomulusImage', Exec) {
     commandLine 'docker', 'push', "gcr.io/${rootProject.gcpProject}/nomulus"
+    dependsOn(tasks.named('tagNomulusImage'))
 }
 
 tasks.register('run', JavaExec) {
@@ -99,11 +78,12 @@ tasks.register('run', JavaExec) {
     workingDir(layout.buildDirectory.dir('jetty-base'))
     classpath = files(jetty_home + '/start.jar')
     systemProperty('google.registry.environment', environment)
+    systemProperty('java.util.logging.config.file', "${projectDir}/logging.properties")
     dependsOn(tasks.named('stage'))
 }
 
 tasks.register('deployNomulus', Exec) {
-    dependsOn(tasks.named('pushNomulusImage'), tasks.named(":proxy:pushProxyImage"))
+    dependsOn('pushNomulusImage', ':proxy:pushProxyImage')
     configure verifyDeploymentConfig
     commandLine './deploy-nomulus-for-env.sh', "${rootProject.environment}"
 }