diff --git a/Dockerfile b/Dockerfile index 1b4d0a8a2..f9eee2d08 100644 --- a/Dockerfile +++ b/Dockerfile @@ -30,10 +30,25 @@ RUN mkdir /download && \ tar xzf apache-tomcat-*tar.gz && \ mv apache-tomcat-9.0.112 /usr/local/tomcat/ && \ cd / && \ - rm -rf /download && \ rm -rf /usr/local/tomcat/webapps/* && \ mkdir /usr/local/tomcat/webapps/ROOT && \ - echo "Nothing to see here" > /usr/local/tomcat/webapps/ROOT/index.html + echo "Nothing to see here" > /usr/local/tomcat/webapps/ROOT/index.html && \ + mkdir -p /usr/local/tomecat/conf/Catalina/localhost +# Now replace the Tomcat logging with logback +# NOTE: I have review this method in jd-gui and do not see anything malicious, packages are isolated to avoid issues +# with other code. +# Additionally, when we are not also accounting for some legacy systems, we will likely shift to +# Jetty to simplify the deployment process, making this subtitution unnecessary. +RUN cd /download && \ + wget https://repo1.maven.org/maven2/com/github/tomcat-slf4j-logback/tomcat9-slf4j-logback/9.0.115/tomcat9-slf4j-logback-9.0.115.jar && \ + echo "cb463fb246fbb326d91b04a7280474f2b722b11cc9d3d7f6c3dbbefcff2c07e055f479d436ab785668d6fa90d0bfd325c86c4fa3a9ad9521159a2a3114916d91 *tomcat9-slf4j-logback-9.0.115.jar" > checksum.logback.txt && \ + sha512sum -c checksum.logback.txt +RUN cd /download && \ + cp tomcat9-slf4j-logback-9.0.115.jar /usr/local/tomcat/bin/tomcat-juli.jar && \ + rm /usr/local/tomcat/conf/logging.properties && \ + rm -rf /download + + CMD ["/usr/local/tomcat/bin/catalina.sh","run"] FROM tomcat_base AS api @@ -43,6 +58,9 @@ COPY --from=builder /builddir/cwms-data-api/build/docker/context.xml /usr/local/ COPY --from=builder /builddir/cwms-data-api/build/docker/server.xml /usr/local/tomcat/conf COPY --from=builder /builddir/cwms-data-api/build/docker/setenv.sh /usr/local/tomcat/bin COPY --from=builder /builddir/cwms-data-api/build/docker/libs/ /usr/local/tomcat/lib +COPY --from=builder /builddir/cwms-data-api/build/docker/logback.xml /logback.xml +COPY --from=builder /builddir/cwms-data-api/build/docker/logback-juli.xml /logback-juli.xml +COPY --from=builder /builddir/cwms-data-api/build/docker/app-context.xml /usr/local/tomcat/conf/Catalina/localhost/cwms-data.xml ENV CDA_JDBC_DRIVER="oracle.jdbc.driver.OracleDriver" ENV CDA_JDBC_URL="" diff --git a/cda-gui/package-lock.json b/cda-gui/package-lock.json index 8f53de641..79b131866 100644 --- a/cda-gui/package-lock.json +++ b/cda-gui/package-lock.json @@ -102,6 +102,7 @@ "integrity": "sha512-yDBHV9kQNcr2/sUr9jghVyz9C3Y5G2zUM2H2lo+9mKv4sFgbA8s8Z9t8D1jiTkGoO/NoIfKMyKWr4s6CN23ZwQ==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "@ampproject/remapping": "^2.2.0", "@babel/code-frame": "^7.27.1", @@ -1524,6 +1525,7 @@ "resolved": "https://registry.npmjs.org/@tanstack/react-query/-/react-query-5.64.1.tgz", "integrity": "sha512-vW5ggHpIO2Yjj44b4sB+Fd3cdnlMJppXRBJkEHvld6FXh3j5dwWJoQo7mGtKI2RbSFyiyu/PhGAy0+Vv5ev9Eg==", "license": "MIT", + "peer": true, "dependencies": { "@tanstack/query-core": "5.64.1" }, @@ -1677,6 +1679,7 @@ "resolved": "https://registry.npmjs.org/@usace/groundwork/-/groundwork-3.14.18.tgz", "integrity": "sha512-wGMhnLvCPO8G4JTyW3EIPNeK4M9AWN6tyht46Fw0CNPpSpO5Fxy8cMfW5UtBS0VXxl6qPAcJdg7EnxY1/heSag==", "license": "MIT", + "peer": true, "dependencies": { "@headlessui/react": "^2.2.0", "@tailwindcss/forms": "^0.5.9", @@ -1718,6 +1721,7 @@ "integrity": "sha512-cl669nCJTZBsL97OF4kUQm5g5hC2uihk0NxY3WENAC0TYdILVkAyHymAntgxGkl7K+t0cXIrH5siy5S4XkFycA==", "dev": true, "license": "MIT", + "peer": true, "bin": { "acorn": "bin/acorn" }, @@ -2064,6 +2068,7 @@ } ], "license": "MIT", + "peer": true, "dependencies": { "caniuse-lite": "^1.0.30001688", "electron-to-chromium": "^1.5.73", @@ -2745,6 +2750,7 @@ "resolved": "https://registry.npmjs.org/eslint/-/eslint-8.57.0.tgz", "integrity": "sha512-dZ6+mexnaTIbSBZWgou51U6OmzIhYM2VcNdtiTtI7qPNZm35Akpr0f6vtw3w1Kmn5PYo+tZVfh13WrhpS6oLqQ==", "dev": true, + "peer": true, "dependencies": { "@eslint-community/eslint-utils": "^4.2.0", "@eslint-community/regexpp": "^4.6.1", @@ -4880,6 +4886,7 @@ } ], "license": "MIT", + "peer": true, "dependencies": { "nanoid": "^3.3.11", "picocolors": "^1.1.1", @@ -5120,6 +5127,7 @@ "version": "18.2.0", "resolved": "https://registry.npmjs.org/react/-/react-18.2.0.tgz", "integrity": "sha512-/3IjMdb2L9QbBdWiW5e3P2/npwMBaU9mHCSCUzNln0ZCYbcfTsGbTJrU/kGemdH2IWmB2ioZ+zkxtmq6g09fGQ==", + "peer": true, "dependencies": { "loose-envify": "^1.1.0" }, @@ -5131,6 +5139,7 @@ "version": "18.2.0", "resolved": "https://registry.npmjs.org/react-dom/-/react-dom-18.2.0.tgz", "integrity": "sha512-6IMTriUmvsjHUjNtEDudZfuDQUoWXVxKHhlEGSk81n4YFS+r/Kl99wXiwlVXtPBtJenozv2P+hxDsw9eA7Xo6g==", + "peer": true, "dependencies": { "loose-envify": "^1.1.0", "scheduler": "^0.23.0" @@ -5225,7 +5234,8 @@ "version": "28.1.0", "resolved": "https://registry.npmjs.org/redux-bundler/-/redux-bundler-28.1.0.tgz", "integrity": "sha512-dbq0J0Sm0ctK9ZUh73JR/6J937qzNvkKEHXtHv7p2Hl/9sS+xyRQReWjuju8LHopYFiG+U0Lg9XZM1hPp1WkHg==", - "license": "MIT" + "license": "MIT", + "peer": true }, "node_modules/redux-bundler-hook": { "version": "1.0.3", @@ -5872,6 +5882,7 @@ "version": "3.4.3", "resolved": "https://registry.npmjs.org/tailwindcss/-/tailwindcss-3.4.3.tgz", "integrity": "sha512-U7sxQk/n397Bmx4JHbJx/iSOOv5G+II3f1kpLpY2QeUv5DcPdcTsYLlusZfq1NthHS1c1cZoyFmmkex1rzke0A==", + "peer": true, "dependencies": { "@alloc/quick-lru": "^5.2.0", "arg": "^5.0.2", @@ -5986,6 +5997,7 @@ "integrity": "sha512-QP88BAKvMam/3NxH6vj2o21R6MjxZUAd6nlwAS/pnGvN9IVLocLHxGYIzFhg6fUQ+5th6P4dv4eW9jX3DSIj7A==", "dev": true, "license": "MIT", + "peer": true, "engines": { "node": ">=12" }, @@ -6191,6 +6203,7 @@ "integrity": "sha512-BxAKBWmIbrDgrokdGZH1IgkIk/5mMHDreLDmCJ0qpyJaAteP8NvMhkwr/ZCQNqNH97bw/dANTE9PDzqwJghfMQ==", "dev": true, "license": "MIT", + "peer": true, "dependencies": { "esbuild": "^0.25.0", "fdir": "^6.5.0", @@ -6284,6 +6297,7 @@ "integrity": "sha512-QP88BAKvMam/3NxH6vj2o21R6MjxZUAd6nlwAS/pnGvN9IVLocLHxGYIzFhg6fUQ+5th6P4dv4eW9jX3DSIj7A==", "dev": true, "license": "MIT", + "peer": true, "engines": { "node": ">=12" }, diff --git a/cwms-data-api/build.gradle b/cwms-data-api/build.gradle index ac38b5518..378609963 100644 --- a/cwms-data-api/build.gradle +++ b/cwms-data-api/build.gradle @@ -21,7 +21,7 @@ configurations { } configurations.implementation { - exclude group: 'com.oracle.database.jdbc' + exclude group: 'com.oracle.database.jdbc' } configurations.all { @@ -29,6 +29,7 @@ configurations.all { exclude group: 'org.apache.xmlbeans' exclude group: 'org.apache.poi' exclude group: 'org.bouncycastle' + exclude group: 'org.apache.tomcat', module: 'tomcat-juli' } dependencies { @@ -64,7 +65,7 @@ dependencies { } implementation(files("$buildDir/libs/${project.name}-${project.version}-codegen-shadow.jar")) - implementation(libs.slf4j) + compileOnly(libs.slf4j) implementation(libs.monolith) { //exclude group: "org.python", module: "jython-standalone" @@ -75,7 +76,8 @@ dependencies { implementation(libs.google.flogger.api) implementation(libs.google.findbugs) implementation(libs.google.errorProne) - runtimeOnly(libs.google.flogger.backend) + implementation(project(":flogger-cda-context")) + runtimeOnly(libs.google.flogger.system.backend) implementation(libs.nucleus.data) { exclude group: "org.jdom" @@ -153,16 +155,22 @@ dependencies { tomcatLibs(libs.bundles.tomcat.embedded) tomcatLibs(libs.bundles.tomcat.support) + + implementation(libs.slf4j) + testImplementation(libs.slf4j.jul) tomcatLibs(libs.google.flogger.api) - tomcatLibs(libs.google.flogger.backend) + tomcatLibs(libs.google.flogger.system.backend) + baseLibs(libs.google.flogger.slf4j.backend) { + exclude group: "org.slf4j" + } + + baseLibs(libs.ch.qos.logback) testImplementation(libs.bundles.testcontainers) testImplementation(libs.apache.commons.csv) testImplementation(libs.cwms.tomcat.auth) - testImplementation(libs.apache.freemarker) - - testRuntimeOnly("org.slf4j:slf4j-jdk14:2.0.16") + testImplementation(libs.apache.freemarker) webjars(project(":cda-gui")) @@ -186,7 +194,10 @@ task extractWebJars(type: Copy) { war { dependsOn extractWebJars from "$buildDir/extra" - from "src/resources/" + from "src/resources/" + // classpath = classpath.filter { file -> + // !file.name.contains("slf4j-api") + // } manifest { attributes "build-version": project.version @@ -256,6 +267,7 @@ task run(type: JavaExec) { args "$buildDir/tomcat", "$buildDir/libs/${project.name}-${project.version}.war", context jvmArgs += "-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager" jvmArgs += "-Djava.util.logging.config.file=$projectDir/logging.properties" + jvmArgs += "-Dlogback.configurationFile=${projectDir}/logback.xml" jvmArgs += "-DTOMCAT_RESOURCES=$buildDir/tomcat/conf/context.xml" jvmArgs += "-Dorg.apache.tomcat.util.digester.PROPERTY_SOURCE=org.apache.tomcat.util.digester.EnvironmentPropertySource" jvmArgs += "-Dcatalina.base=$buildDir/tomcat" @@ -285,6 +297,7 @@ task integrationTests(type: Test) { jvmArgs += "-DwarContext=/cwms-data" jvmArgs += "-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager" jvmArgs += "-Djava.util.logging.config.file=$projectDir/logging.properties" + jvmArgs += "-Dlogback.configurationFile=${projectDir}/logback.xml" jvmArgs += "-Dorg.apache.tomcat.util.digester.PROPERTY_SOURCE=org.apache.tomcat.util.digester.EnvironmentPropertySource" jvmArgs += "-Dcwms.dataapi.access.provider=MultipleAccessManager" jvmArgs += "-Dcwms.dataapi.access.providers=KeyAccessManager,CwmsAccessManager" @@ -302,6 +315,7 @@ task prepareDockerBuild(type: Copy, dependsOn: war) { from(configurations.baseLibs) { into "libs" + //exclude "**/logback*" } from(sourceSets.test.resources) { diff --git a/cwms-data-api/logback.xml b/cwms-data-api/logback.xml new file mode 100644 index 000000000..a41294014 --- /dev/null +++ b/cwms-data-api/logback.xml @@ -0,0 +1,29 @@ + + + + + + + + CWMS-Data-API + + + System.err + + + + + false + true + build/cda.log + + + + + + + + + + + \ No newline at end of file diff --git a/cwms-data-api/src/docker/app-context.xml b/cwms-data-api/src/docker/app-context.xml new file mode 100644 index 000000000..79c880dbc --- /dev/null +++ b/cwms-data-api/src/docker/app-context.xml @@ -0,0 +1,8 @@ + + + + \ No newline at end of file diff --git a/cwms-data-api/src/docker/logback-juli.xml b/cwms-data-api/src/docker/logback-juli.xml new file mode 100644 index 000000000..813d4a25c --- /dev/null +++ b/cwms-data-api/src/docker/logback-juli.xml @@ -0,0 +1,29 @@ + + + + + + + + CWMS-Data-API + + + System.err + + + + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/cwms-data-api/src/docker/logback.xml b/cwms-data-api/src/docker/logback.xml new file mode 100644 index 000000000..6578bb5e4 --- /dev/null +++ b/cwms-data-api/src/docker/logback.xml @@ -0,0 +1,29 @@ + + + + + + + + CWMS-Data-API + + + System.err + + + + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/cwms-data-api/src/docker/setenv.sh b/cwms-data-api/src/docker/setenv.sh index 62aa549f5..62e747ae1 100755 --- a/cwms-data-api/src/docker/setenv.sh +++ b/cwms-data-api/src/docker/setenv.sh @@ -1 +1,5 @@ -export CATALINA_OPTS="$CATALINA_OPTS -Dorg.apache.tomcat.util.digester.PROPERTY_SOURCE=org.apache.tomcat.util.digester.EnvironmentPropertySource" +CATALINA_OPTS="$CATALINA_OPTS -Dorg.apache.tomcat.util.digester.PROPERTY_SOURCE=org.apache.tomcat.util.digester.EnvironmentPropertySource" +CATALINA_OPTS="$CATALINA_OPTS -Djuli-logback.configurationFile=/logback-juli.xml -Djuli-logback.ContextSelector=JNDI" +CATALINA_OPTS="$CATALINA_OPTS -Dlogback.configurationFile=/logback.xml -Dlogback.ContextSelector=JNDI" + +export CATALINA_OPTS \ No newline at end of file diff --git a/cwms-data-api/src/main/java/cwms/cda/data/dao/RatingMetadataDao.java b/cwms-data-api/src/main/java/cwms/cda/data/dao/RatingMetadataDao.java index fe4a62236..72d798b5e 100644 --- a/cwms-data-api/src/main/java/cwms/cda/data/dao/RatingMetadataDao.java +++ b/cwms-data-api/src/main/java/cwms/cda/data/dao/RatingMetadataDao.java @@ -63,6 +63,8 @@ import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; import com.google.common.flogger.FluentLogger; +import com.google.common.flogger.context.ScopedLoggingContexts; + import java.util.stream.Collectors; import java.util.stream.Stream; @@ -190,9 +192,12 @@ public Map> getRatingsForIds( boolean useParallel = true; Stream>> mapStream; if (useParallel) { + // get current context to pass in to Thread. Otherwise any log message would not include the Trace ID. + final var loggingContext = ScopedLoggingContexts.newContext(); mapStream = ratingIds.stream() .map(ratingId -> CompletableFuture.supplyAsync(() -> - retrieveRatings(office, ratingId, start, end), executor)) + loggingContext.callUnchecked(() -> retrieveRatings(office, ratingId, start, end)) + , executor)) .collect(Collectors.toList()) .stream() .map(CompletableFuture::join); @@ -221,7 +226,6 @@ public Map> getRatingsForIds( public Map> retrieveRatings( String office, String templateIdMask, ZonedDateTime start, ZonedDateTime end) { Map> retVal = new LinkedHashMap<>(); - try (final Timer.Context ignored = markAndTime("retrieveRatings")) { RatingSpecDao ratingSpecDao = new RatingSpecDao(dsl); Optional spec = ratingSpecDao.retrieveRatingSpec(office, templateIdMask); diff --git a/cwms-data-api/src/main/java/cwms/cda/logging/TraceIdFilter.java b/cwms-data-api/src/main/java/cwms/cda/logging/TraceIdFilter.java new file mode 100644 index 000000000..62974f1d8 --- /dev/null +++ b/cwms-data-api/src/main/java/cwms/cda/logging/TraceIdFilter.java @@ -0,0 +1,58 @@ +package cwms.cda.logging; + +import java.io.IOException; +import java.util.UUID; +import java.util.regex.Pattern; + +import javax.servlet.Filter; +import javax.servlet.FilterChain; +import javax.servlet.ServletException; +import javax.servlet.ServletRequest; +import javax.servlet.ServletResponse; +import javax.servlet.annotation.WebFilter; +import javax.servlet.http.HttpServletRequest; + +import com.google.common.flogger.MetadataKey; +import com.google.common.flogger.context.ScopedLoggingContexts; + +@WebFilter("/*") +public class TraceIdFilter implements Filter +{ + public static final String CONTEXT_TRACE_ID = "traceID"; + public static final String HEADER_TRACE_ID = "X-Trace-ID"; + + public static final Pattern UUID_MATCHER = Pattern.compile("[a-z0-9]{8}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{12}"); + + @Override + public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) + throws IOException, ServletException { + if (request instanceof HttpServletRequest) { + var httpRequest = (HttpServletRequest)request; + + var xTraceId = httpRequest.getHeader(HEADER_TRACE_ID); + String traceId = null; + if (xTraceId == null || xTraceId.isBlank()) { + traceId = UUID.randomUUID().toString(); + } else { + traceId = validate(xTraceId); //well that needs some validation. + } + ScopedLoggingContexts.newContext() + .withMetadata(MetadataKey.single("traceId", String.class), traceId) + .callUnchecked(() -> { + chain.doFilter(httpRequest, response); + return null; + }); + } else { + chain.doFilter(request, response); + } + } + + private static String validate(String id) throws IOException + { + if (UUID_MATCHER.matcher(id).matches()) { + return id; + } else { + throw new IOException("Trace id '" + id + "' is not a valid UUIDish value."); + } + } +} diff --git a/cwms-data-api/src/test/java/cwms/cda/api/DataApiTestIT.java b/cwms-data-api/src/test/java/cwms/cda/api/DataApiTestIT.java index e314eb06b..e598f02f0 100644 --- a/cwms-data-api/src/test/java/cwms/cda/api/DataApiTestIT.java +++ b/cwms-data-api/src/test/java/cwms/cda/api/DataApiTestIT.java @@ -153,18 +153,18 @@ private static Template loadTemplateFromResource(String resource) throws Excepti @BeforeAll public static void load_queries() throws Exception { createLocationQuery = IOUtils.toString( - TimeseriesControllerTestIT.class + TimeSeriesControllerTestIT.class .getClassLoader() .getResourceAsStream("cwms/cda/data/sql_templates/create_location.sql"), "UTF-8" ); createTimeseriesQuery = IOUtils.toString( - TimeseriesControllerTestIT.class + TimeSeriesControllerTestIT.class .getClassLoader() .getResourceAsStream("cwms/cda/data/sql_templates/create_timeseries.sql"), "UTF-8" ); createTimeseriesOffsetQuery = IOUtils.toString( - TimeseriesControllerTestIT.class + TimeSeriesControllerTestIT.class .getClassLoader() .getResourceAsStream("cwms/cda/data/sql_templates/create_timeseries_offset.sql"), "UTF-8" ); diff --git a/cwms-data-api/src/test/java/cwms/cda/api/TimeseriesControllerTestIT.java b/cwms-data-api/src/test/java/cwms/cda/api/TimeSeriesControllerTestIT.java similarity index 99% rename from cwms-data-api/src/test/java/cwms/cda/api/TimeseriesControllerTestIT.java rename to cwms-data-api/src/test/java/cwms/cda/api/TimeSeriesControllerTestIT.java index 9e69627c8..2fa6cbfc6 100644 --- a/cwms-data-api/src/test/java/cwms/cda/api/TimeseriesControllerTestIT.java +++ b/cwms-data-api/src/test/java/cwms/cda/api/TimeSeriesControllerTestIT.java @@ -67,7 +67,7 @@ import java.util.List; @Tag("integration") -final class TimeseriesControllerTestIT extends DataApiTestIT { +final class TimeSeriesControllerTestIT extends DataApiTestIT { public static final int MINIMUM_SCHEMA = 999999; @Test diff --git a/cwms-data-api/src/test/java/cwms/cda/api/rating/RatingSpecControllerTestIT.java b/cwms-data-api/src/test/java/cwms/cda/api/rating/RatingSpecControllerTestIT.java index 4e41a849e..42d594997 100644 --- a/cwms-data-api/src/test/java/cwms/cda/api/rating/RatingSpecControllerTestIT.java +++ b/cwms-data-api/src/test/java/cwms/cda/api/rating/RatingSpecControllerTestIT.java @@ -39,6 +39,7 @@ import cwms.cda.data.dto.rating.RatingSpec; import cwms.cda.formatters.ContentType; import cwms.cda.formatters.Formats; +import cwms.cda.logging.TraceIdFilter; import javax.servlet.http.HttpServletResponse; import java.util.stream.IntStream; @@ -58,6 +59,7 @@ class RatingSpecControllerTestIT extends DataApiTestIT { @Test void test_empty_rating_spec() throws Exception { + final String TEST_TRACE_ID = "be4710da-7931-4cb9-a621-1ab46ecc1022"; String locationId = "RatingSpecTestEmpty"; String officeId = "SPK"; createLocation(locationId, true, officeId); @@ -77,6 +79,7 @@ void test_empty_rating_spec() throws Exception { .contentType(Formats.XMLV2) .body(templateXml) .header("Authorization", user.toHeaderValue()) + .header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID) .queryParam(OFFICE, officeId) .when() .redirects().follow(true) @@ -93,6 +96,7 @@ void test_empty_rating_spec() throws Exception { .contentType(Formats.XMLV2) .body(specXml) .header("Authorization", user.toHeaderValue()) + .header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID) .queryParam(OFFICE, officeId) .when() .redirects().follow(true) @@ -109,6 +113,7 @@ void test_empty_rating_spec() throws Exception { Response response = given() .log().ifValidationFails(LogDetail.ALL,true) .accept(Formats.JSONV2) + .header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID) .queryParam(PAGE_SIZE, 500) .when() .redirects().follow(true) @@ -127,6 +132,7 @@ void test_empty_rating_spec() throws Exception { .log().ifValidationFails(LogDetail.ALL,true) .accept(Formats.JSONV2) .contentType(Formats.JSONV2) + .header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID) .queryParam(OFFICE, officeId) .queryParam(RATING_ID_MASK, specContainer.specId) .when() @@ -146,6 +152,7 @@ void test_empty_rating_spec() throws Exception { .accept(Formats.JSONV2) .contentType(Formats.JSONV2) .header("Authorization", user.toHeaderValue()) + .header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID) .queryParam(OFFICE, officeId) .queryParam(METHOD, JooqDao.DeleteMethod.DELETE_ALL) .when() diff --git a/cwms-data-api/src/test/java/fixtures/CwmsDataApiSetupCallback.java b/cwms-data-api/src/test/java/fixtures/CwmsDataApiSetupCallback.java index 7781b7ca0..4656633cc 100644 --- a/cwms-data-api/src/test/java/fixtures/CwmsDataApiSetupCallback.java +++ b/cwms-data-api/src/test/java/fixtures/CwmsDataApiSetupCallback.java @@ -9,6 +9,7 @@ import java.time.Duration; import java.util.ArrayList; import java.util.List; +import java.util.logging.LogManager; import org.apache.catalina.Manager; import org.apache.commons.io.IOUtils; @@ -21,6 +22,7 @@ import org.junit.jupiter.api.extension.BeforeAllCallback; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.api.extension.ExtensionContext; +import org.slf4j.bridge.SLF4JBridgeHandler; import com.google.common.flogger.FluentLogger; @@ -74,6 +76,12 @@ public class CwmsDataApiSetupCallback implements BeforeAllCallback,AfterAllCallb VERSION_INT = versionInt(); } + static { + //LogManager.getLogManager().reset(); + SLF4JBridgeHandler.removeHandlersForRootLogger(); + SLF4JBridgeHandler.install(); + } + private static String schemaVersion() { String ret; diff --git a/cwms-data-api/src/test/java/fixtures/TomcatServer.java b/cwms-data-api/src/test/java/fixtures/TomcatServer.java index ed196461c..5dddf8a6d 100644 --- a/cwms-data-api/src/test/java/fixtures/TomcatServer.java +++ b/cwms-data-api/src/test/java/fixtures/TomcatServer.java @@ -30,6 +30,7 @@ public class TomcatServer { private Tomcat tomcatInstance = null; private Manager sessionManager = null; private SingleSignOnWrapper ssoValve = new SingleSignOnWrapper(); + /** * Setups the baseline for tomcat to run. * @param baseDir set to the CATALINA_BASE directory the build has setup diff --git a/cwms-data-api/src/test/resources/tomcat/conf/context.xml b/cwms-data-api/src/test/resources/tomcat/conf/context.xml index a6c898bb7..1e0a939d2 100644 --- a/cwms-data-api/src/test/resources/tomcat/conf/context.xml +++ b/cwms-data-api/src/test/resources/tomcat/conf/context.xml @@ -1,5 +1,5 @@ - + TRACE_ID = MetadataKey.single("traceId", String.class); + + @Override + public Builder newContext() { + return new CdaBuilder(); + } + + @Override + public Builder newContext(ScopeType scopeType) { + return new CdaBuilder(); + } + + + public static final class CdaBuilder extends Builder { + + + private final Map atCreationMdc; + + public CdaBuilder() { + var tmp = MDC.getCopyOfContextMap(); // get copy at time of creation of this context + atCreationMdc = tmp == null ? new HashMap<>() : tmp; + } + + /** + * Takes the MDC values that existed at the time of creation of this new Context + * and the most recent context then adds the Metadata/Tag values that were set + * on this context. + * + * MDC data is ThreadLocal, so the above behavior is required to allow the context to + * properly propagate to threads, where are currently used in the {@see RatingMetaDataDao} (though no logging is done there) + * + */ + @Override + public LoggingContextCloseable install() { + final var meta = this.getMetadata(); + final var currentMdc = MDC.getCopyOfContextMap(); + + atCreationMdc.putAll(atCreationMdc); + MDC.setContextMap(atCreationMdc); + + if (meta != null) { + for (int i = 0; i < meta.size(); i++) { + var key = meta.getKey(i); + var val = meta.getValue(i); + MDC.put(key.getLabel(), val.toString()); + } + } + + final var tags = this.getTags(); + if (tags != null) { + tags.asMap().forEach((key, entry) -> + MDC.put(key, String.join(",", entry.stream() + .map(Object::toString) + .collect(Collectors.toList()))) + ); + } + + // Just reset back the MDC map to whatever it was before we decided to muck with it. + return () -> { + MDC.clear(); + MDC.setContextMap(currentMdc); + }; + } + } +} diff --git a/flogger-cda-context/src/test/java/cwms/cda/logging/CdaLoggingContextTest.java b/flogger-cda-context/src/test/java/cwms/cda/logging/CdaLoggingContextTest.java new file mode 100644 index 000000000..8c24bc117 --- /dev/null +++ b/flogger-cda-context/src/test/java/cwms/cda/logging/CdaLoggingContextTest.java @@ -0,0 +1,145 @@ +package cwms.cda.logging; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +import com.google.common.flogger.FluentLogger; +import com.google.common.flogger.MetadataKey; +import com.google.common.flogger.context.ScopedLoggingContexts; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.AppenderBase; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import static cwms.cda.logging.CdaLoggingContext.TRACE_ID; + +class CdaLoggingContextTest { + + private static final FluentLogger logger = FluentLogger.forEnclosingClass(); + private static final MemoryAppender memoryAppender = new MemoryAppender(); + + private static final MetadataKey NESTED_KEY = MetadataKey.single("nestedKey", String.class); + + @BeforeAll + static void setup_logger() { + LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); + var logbackLogger = context.getLogger(CdaLoggingContextTest.class); + memoryAppender.setContext(context); + memoryAppender.setName(CdaLoggingContextTest.class.getName()); + memoryAppender.start(); + + logbackLogger.addAppender(memoryAppender); + logbackLogger.setAdditive(false); + } + + @AfterEach + void clear_logger() { + memoryAppender.clear(); + } + + @Test + void test_basic_logging_context() { + ScopedLoggingContexts.newContext() + .withMetadata(TRACE_ID, "test-trace-id") + .run(() -> logger.atInfo().log("hello")); + + var messages = memoryAppender.getEvents(); + assertFalse(messages.isEmpty()); + boolean foundMsg = false; + boolean foundId = false; + for (var msg: messages) { + if (msg.getMessage().contains("hello")) { + foundMsg = true; + } + if ("test-trace-id".equals(msg.getMDCPropertyMap().get("traceId"))) { + foundId = true; + } + + } + assertTrue(foundMsg, "Message was not in log."); + assertTrue(foundId, "trace id was not present in the log messages"); + } + + @Test + void test_nested_scopes() { + final var ctx = ScopedLoggingContexts.newContext() + .withMetadata(TRACE_ID, "test-trace-id"); + + ctx.run(() -> { + logger.atInfo().log("hello not nested"); + ScopedLoggingContexts.newContext() + .withMetadata(NESTED_KEY, "nestEgg") + .run(() -> logger.atInfo().log("hello nested")); + }); + + final var messages = memoryAppender.getEvents(); + assertEquals(2, messages.size()); + final var notNestedEvent = messages.get(0); + final var nestedEvent = messages.get(1); + + assertFalse(notNestedEvent.getMDCPropertyMap().containsKey(NESTED_KEY.getLabel())); + assertEquals("test-trace-id", notNestedEvent.getMDCPropertyMap().get(TRACE_ID.getLabel())); + + assertEquals("nestEgg", nestedEvent.getMDCPropertyMap().get(NESTED_KEY.getLabel())); + assertEquals("test-trace-id", nestedEvent.getMDCPropertyMap().get(TRACE_ID.getLabel())); + } + + @Test + void test_nested_scope_in_theory() throws Exception { + try (var ctx = ScopedLoggingContexts.newContext() + .withMetadata(TRACE_ID, "test-trace-id") + .install()) { + logger.atInfo().log("before thread"); + final var forThreadCtx = ScopedLoggingContexts.newContext(); + var thread = new Thread(() -> { + forThreadCtx.withMetadata(NESTED_KEY, "threadEgg") + .run(() -> logger.atInfo().log("in thread")); + }); + + thread.start(); + thread.join(); + + final var messages = memoryAppender.getEvents(); + assertEquals(2, messages.size()); + final var notNestedEvent = messages.get(0); + final var nestedEvent = messages.get(1); + + assertFalse(notNestedEvent.getMDCPropertyMap().containsKey(NESTED_KEY.getLabel())); + assertEquals("test-trace-id", notNestedEvent.getMDCPropertyMap().get(TRACE_ID.getLabel())); + + assertEquals("threadEgg", nestedEvent.getMDCPropertyMap().get(NESTED_KEY.getLabel())); + assertEquals("test-trace-id", nestedEvent.getMDCPropertyMap().get(TRACE_ID.getLabel())); + + } + } + + + public static class MemoryAppender extends AppenderBase { + private final List events = Collections.synchronizedList(new ArrayList<>()); + + + @Override + protected void append(ILoggingEvent event) { + event.prepareForDeferredProcessing(); + events.add(event); + } + + public List getEvents() { + return new ArrayList<>(events); // Return a copy to avoid ConcurrentModificationException + } + + public void clear() { + events.clear(); + } + } +} diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index e42071042..9842b0f66 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -4,10 +4,11 @@ jaxb-impl = "3.0.2" jooq-codegen = "26.02.17-RC01-oracle19c" jooq-codegen-shadow = "24.12.04-2025.01.21" jooq = "3.18.7-jdk11" -slf4j = "2.0.9" +slf4j = "2.0.17" hec-monolith = "3.3.20" hec-nucleus = "2.0.1" -flogger = "0.7.4" +flogger = "0.9" +logback = "1.5.32" google-findbugs = "3.0.2" error_prone_annotations = "2.15.0" cwms-ratings = "4.2.3" @@ -55,10 +56,13 @@ jaxb-core = { module = "com.sun.xml.bind:jaxb-core", version.ref = "jaxb-impl" } cwms-db-jooq-codegen = { module = "mil.army.usace.hec:cwms-db-jooq-codegen_java11", version.ref = "jooq-codegen" } cwms-db-jooq-codegen-shadow = { module = "mil.army.usace.hec:cwms-db-jooq-codegen_java8", version.ref = "jooq-codegen-shadow" } jooq = { module = "org.jooq.pro-java-11:jooq", version.ref ="jooq" } -slf4j = { module = "org.slf4j:slf4j-jdk14", version.ref = "slf4j" } +slf4j = { module = "org.slf4j:slf4j-api", version.ref = "slf4j" } +slf4j-jul = { module = "org.slf4j:jul-to-slf4j", version.ref = "slf4j" } monolith = { module = "mil.army.usace.hec:hec-monolith", version.ref = "hec-monolith" } google-flogger-api = { module = "com.google.flogger:flogger", version.ref = "flogger" } -google-flogger-backend = { module = "com.google.flogger:flogger-system-backend", version.ref = "flogger" } +google-flogger-system-backend = { module = "com.google.flogger:flogger-system-backend", version.ref = "flogger" } +google-flogger-slf4j-backend = { module = "com.google.flogger:flogger-slf4j-backend", version.ref = "flogger" } +ch-qos-logback = { module = "ch.qos.logback:logback-classic", version.ref = "logback" } google-findbugs = { module = "com.google.code.findbugs:jsr305", version.ref = "google-findbugs" } google-errorProne = { module = "com.google.errorprone:error_prone_annotations", version.ref = "error_prone_annotations"} nucleus-data = { module = "mil.army.usace.hec:hec-nucleus-data", version.ref = "hec-nucleus" } @@ -128,7 +132,7 @@ javaparser-symbol-solver-core = { module = "com.github.javaparser:javaparser-sym tomcat-embedded-core = { module = "org.apache.tomcat.embed:tomcat-embed-core", version.ref = "tomcat" } tomcat-embedded-jasper = { module = "org.apache.tomcat.embed:tomcat-embed-jasper", version.ref = "tomcat" } -tomcat-juli = { module = "org.apache.tomcat:tomcat-juli", version.ref = "tomcat" } +# tomcat-juli = { module = "org.apache.tomcat:tomcat-juli", version.ref = "tomcat" } tomcat-jdbc = { module = "org.apache.tomcat:tomcat-jdbc", version.ref = "tomcat" } @@ -143,7 +147,7 @@ com-google-auto-service = { module = "com.google.auto.service:auto-service", ver [bundles] junit = ["junit-jupiter-api", "junit-jupiter-params", "junit-jupiter-engine", "junit-platform-launcher"] tomcat-embedded = [ "tomcat-embedded-core", "tomcat-embedded-jasper" ] -tomcat-support = [ "tomcat-juli", "tomcat-jdbc" ] +tomcat-support = [ "tomcat-jdbc" ] testcontainers = [ "testcontainers-base", "testcontainers-database-commons", "testcontainers-jdbc", "testcontainers-junit-jupiter", "testcontainers-cwms", "testcontainers-minio" ] metrics = ["metrics-core", "metrics-servlets", "metrics-prometheus-client", "metrics-prometheus-servlets" ] diff --git a/settings.gradle b/settings.gradle index b4aa2658a..ea9567100 100644 --- a/settings.gradle +++ b/settings.gradle @@ -14,5 +14,6 @@ include ":access-manager-api" include ":cwms-data-api" include ":cda-gui" include ":docs" +include ":flogger-cda-context" project(":docs").projectDir = file("docs") include ":cda-client" \ No newline at end of file