fix: web validator logging (#2026)

Author: davidgamez

core/src/main/java/org/mobilitydata/gtfsvalidator/performance/MemoryUsageRegister.java

@@ -82,7 +82,7 @@ public MemoryUsage registerMemoryUsage(String key, MemoryUsage previous) {
    */
   public void registerMemoryUsage(MemoryUsage memoryUsage) {
     registry.add(memoryUsage);
-    logger.atInfo().log(memoryUsage.humanReadablePrint());
+    logger.atFinest().log(memoryUsage.humanReadablePrint());
   }
 
   /** Clears the memory usage registry. */

main/src/main/java/org/mobilitydata/gtfsvalidator/util/VersionResolver.java

@@ -171,7 +171,7 @@ private Optional<String> resolveLatestReleaseVersion(Optional<String> currentVer
       Gson gson = new GsonBuilder().create();
       VersionResponse response = gson.fromJson(in, VersionResponse.class);
       if (response != null && !Strings.isNullOrEmpty(response.version)) {
-        logger.atInfo().log("resolved release version=%s", response.version);
+        logger.atFinest().log("resolved release version=%s", response.version);
         return Optional.of(response.version);
       }
     }

web/service/Dockerfile

@@ -26,4 +26,9 @@ COPY ${JAR_FILES} /
 
 ADD ./newrelic/newrelic.jar /newrelic/newrelic.jar
 
+ENV SPRING_PROFILES_ACTIVE=cloud
+ENV SPRING_MAIN_BANNER-MODE=off
+ENV SENTRY_LOGGING_MINIMUM_EVENT_LEVEL=error
+ENV SENTRY_LOGGING_MINIMUM_BREADCRUMB_LEVEL=info
+
 ENTRYPOINT exec java -Xmx12g  -javaagent:/newrelic/newrelic.jar -jar /service-${CURRENT_VERSION}.jar

web/service/src/main/java/org/mobilitydata/gtfsvalidator/web/service/controller/ValidationController.java

@@ -30,6 +30,7 @@
 import org.mobilitydata.gtfsvalidator.web.service.util.ValidationJobMetaData;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.http.HttpStatus;
 import org.springframework.http.ResponseEntity;
@@ -39,6 +40,7 @@
 @RestController
 public class ValidationController {
 
+  public static final String JOB_ID = "job_id";
   private final Logger logger = LoggerFactory.getLogger(ValidationController.class);
 
   @Autowired private StorageHelper storageHelper;
@@ -110,6 +112,9 @@ public ResponseEntity runValidator(
 
       ValidationJobMetaData jobData = getFeedFileMetaData(message);
       jobId = jobData.getJobId();
+      MDC.put(JOB_ID, jobId);
+
+      logger.info("Validation started for job ID: {}", jobId);
 
       var fileName = jobData.getFileName();
 
@@ -142,12 +147,27 @@ public ResponseEntity runValidator(
       Sentry.captureException(exc);
       throw new ResponseStatusException(HttpStatus.INTERNAL_SERVER_ERROR, "Error", exc);
     } finally {
+      MDC.remove(JOB_ID);
       // delete the temp file and directory
-      if (tempFile != null) {
-        tempFile.delete();
-      }
+      safeDeleteFile(tempFile);
       if (outputPath != null) {
-        outputPath.toFile().delete();
+        safeDeleteFile(outputPath.toFile());
+      }
+    }
+  }
+
+  /**
+   * Deletes the temp file and directory. Exception is logged but not thrown as it's not considered
+   * a validation error.
+   *
+   * @param file to be deleted
+   */
+  private void safeDeleteFile(File file) {
+    if (file != null && file.exists()) {
+      try {
+        file.delete();
+      } catch (Exception e) {
+        logger.warn("Error deleting file: {}", file.getAbsolutePath(), e);
       }
     }
   }

web/service/src/main/java/org/mobilitydata/gtfsvalidator/web/service/util/LoggingBridgeConfig.java

@@ -0,0 +1,25 @@
+package org.mobilitydata.gtfsvalidator.web.service.util;
+
+import java.util.logging.LogManager;
+import javax.annotation.PostConstruct;
+import org.slf4j.bridge.SLF4JBridgeHandler;
+import org.springframework.context.annotation.Configuration;
+
+/**
+ * This class sets up a bridge between Java Util Logging (JUL) and SLF4J. It resets the JUL root
+ * logger and installs the SLF4J bridge handler to redirect JUL log messages to SLF4J.
+ */
+@Configuration
+public class LoggingBridgeConfig {
+
+  /**
+   * This method is called after the bean is constructed. It resets the JUL root logger and installs
+   * the SLF4J bridge handler.
+   */
+  @PostConstruct
+  public void setupJulToSlf4jBridge() {
+    LogManager.getLogManager().reset();
+    SLF4JBridgeHandler.removeHandlersForRootLogger();
+    SLF4JBridgeHandler.install();
+  }
+}

web/service/src/main/java/org/mobilitydata/gtfsvalidator/web/service/util/StorageHelper.java

@@ -73,7 +73,7 @@ public void saveJobMetadata(JobMetadata metadata) throws Exception {
       var jobBlobInfo = BlobInfo.newBuilder(jobBlobId).setContentType("application/json").build();
       var om = new ObjectMapper();
       var json = om.writeValueAsString(metadata);
-      logger.info("Saving job metadata: " + json);
+      logger.debug("Saving job metadata: {}", json);
       storage.create(jobBlobInfo, json.getBytes());
     } catch (Exception exc) {
       logger.error("Error setting country code", exc);
@@ -93,13 +93,13 @@ public JobMetadata getJobMetadata(String jobId) {
       var jobBlobId = BlobId.of(JOB_INFO_BUCKET_NAME, jobInfoPath);
       Blob blob = storage.get(jobBlobId);
       var json = new String(blob.getContent());
-      logger.info("Loading job metadata: " + json);
+      logger.debug("Loading job metadata: {}", json);
 
       var objectMapper = new ObjectMapper();
       JobMetadata jobMetadata = objectMapper.readValue(json, JobMetadata.class);
       return jobMetadata;
     } catch (Exception exc) {
-      logger.error("Error could not load remote file, using default country code", exc);
+      logger.debug("No metadata found using default country code");
       return new JobMetadata(jobId, "");
     }
   }
@@ -204,10 +204,10 @@ public void writeExecutionResultFile(
 
     Path executionResultPath = outputPath.resolve(executionResultFile);
     try {
-      logger.info("Writing executionResult file to " + executionResultFile);
+      logger.debug("Writing executionResult file to " + executionResultFile);
       Files.write(
           executionResultPath, gson.toJson(executionResult).getBytes(StandardCharsets.UTF_8));
-      logger.info(executionResultFile + " file written successfully");
+      logger.debug(executionResultFile + " file written successfully");
     } catch (IOException e) {
       logger.error("Error writing to file " + executionResultFile);
       e.printStackTrace();

web/service/src/main/java/org/mobilitydata/gtfsvalidator/web/service/util/ValidationHandler.java

@@ -35,7 +35,7 @@ public void validateFeed(@NonNull File feedFile, @NonNull Path outputPath, Strin
             .setOutputDirectory(outputPath);
     if (!countryCode.isEmpty()) {
       var country = CountryCode.forStringOrUnknown(countryCode);
-      logger.info("setting country code: " + country.getCountryCode());
+      logger.debug("setting country code: {}", country.getCountryCode());
       configBuilder.setCountryCode(CountryCode.forStringOrUnknown(countryCode));
     }
     var config = configBuilder.build();

…b/service/src/main/resources/logback.xml …ce/src/main/resources/logback-spring.xmlweb/service/src/main/resources/logback.xml renamed to web/service/src/main/resources/logback-spring.xml web/service/src/main/resources/logback.xml renamed to web/service/src/main/resources/logback-spring.xml

@@ -1,7 +1,5 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <configuration>
-    <include resource="org/springframework/boot/logging/logback/base.xml"/>
-
     <springProfile name="local">
         <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
             <encoder>
@@ -26,6 +24,20 @@
                 </layout>
             </encoder>
         </appender>
+
+        <!-- Suppress INFO logs from the GTFS validator tables to reduce noise -->
+        <logger name="org.mobilitydata.gtfsvalidator.table" level="WARN" additivity="false" />
+        <!-- Suppress Spring Boot startup noise -->
+        <logger name="org.springframework.boot" level="WARN" />
+        <logger name="org.springframework.context" level="WARN" />
+        <logger name="org.springframework.beans.factory" level="WARN" />
+        <logger name="org.apache.catalina" level="WARN" />
+        <logger name="org.apache.coyote" level="WARN" />
+        <logger name="org.apache.tomcat" level="WARN" />
+        <logger name="org.springframework.web" level="WARN" additivity="false" />
+        <logger name="com.google.cloud.spring.core" level="WARN" />
+        <logger name="com.google.cloud.spring.autoconfigure" level="WARN" />
+
         <root level="INFO">
             <appender-ref ref="CONSOLE_JSON" />
         </root>

web/service/src/test/java/org/mobilitydata/gtfsvalidator/web/service/controller/RunValidatorEndpointTest.java

@@ -83,6 +83,8 @@ public void runValidatorSuccess() throws Exception {
         .when(storageHelper)
         .downloadFeedFileFromStorage(anyString(), anyString());
 
+    doReturn(true).when(mockFeedFile).exists();
+    doReturn(true).when(mockOutputPathToFile).exists();
     mockMvc
         .perform(
             MockMvcRequestBuilders.post("/run-validator")
@@ -101,7 +103,9 @@ public void runValidatorSuccess() throws Exception {
     verify(storageHelper, times(1)).uploadFilesToStorage(testJobId, mockOutputPath);
 
     // verify that the temp files and directory are deleted
+    verify(mockFeedFile, times(1)).exists();
     verify(mockFeedFile, times(1)).delete();
+    verify(mockOutputPathToFile, times(1)).exists();
     verify(mockOutputPathToFile, times(1)).delete();
   }