Skip to content

Commit 65a4205

Browse files
MikeNeilsonMikeNeilson
committed
Working Flogger ScopedLoggerContext.
1 parent 86b3c4d commit 65a4205

File tree

9 files changed

+296
-24
lines changed

9 files changed

+296
-24
lines changed

‎cwms-data-api/build.gradle‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -75,6 +75,7 @@ dependencies {
7575
implementation(libs.google.flogger.api)
7676
implementation(libs.google.findbugs)
7777
implementation(libs.google.errorProne)
78+
implementation(project(":flogger-cda-context"))
7879
runtimeOnly(libs.google.flogger.system.backend)
7980
runtimeOnly(libs.google.flogger.slf4j.backend)
8081
runtimeOnly(libs.ch.qos.logback)

‎cwms-data-api/src/main/java/cwms/cda/data/dao/RatingMetadataDao.java‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -63,6 +63,8 @@
6363
import java.util.concurrent.ThreadPoolExecutor;
6464
import java.util.concurrent.TimeUnit;
6565
import com.google.common.flogger.FluentLogger;
66+
import com.google.common.flogger.context.ScopedLoggingContexts;
67+
6668
import java.util.stream.Collectors;
6769
import java.util.stream.Stream;
6870

@@ -190,9 +192,12 @@ public Map<RatingSpec, Set<AbstractRatingMetadata>> getRatingsForIds(
190192
boolean useParallel = true;
191193
Stream<Map<RatingSpec, Set<AbstractRatingMetadata>>> mapStream;
192194
if (useParallel) {
195+
// get current context to pass in to Thread. Otherwise any log message would not include the Trace ID.
196+
final var loggingContext = ScopedLoggingContexts.newContext();
193197
mapStream = ratingIds.stream()
194198
.map(ratingId -> CompletableFuture.supplyAsync(() ->
195-
retrieveRatings(office, ratingId, start, end), executor))
199+
loggingContext.callUnchecked(() -> retrieveRatings(office, ratingId, start, end))
200+
, executor))
196201
.collect(Collectors.toList())
197202
.stream()
198203
.map(CompletableFuture::join);
@@ -221,7 +226,6 @@ public Map<RatingSpec, Set<AbstractRatingMetadata>> getRatingsForIds(
221226
public Map<RatingSpec, Set<AbstractRatingMetadata>> retrieveRatings(
222227
String office, String templateIdMask, ZonedDateTime start, ZonedDateTime end) {
223228
Map<RatingSpec,Set<AbstractRatingMetadata>> retVal = new LinkedHashMap<>();
224-
225229
try (final Timer.Context ignored = markAndTime("retrieveRatings")) {
226230
RatingSpecDao ratingSpecDao = new RatingSpecDao(dsl);
227231
Optional<RatingSpec> spec = ratingSpecDao.retrieveRatingSpec(office, templateIdMask);

‎cwms-data-api/src/main/java/cwms/cda/logging/TraceIdFilter.java‎

Lines changed: 10 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -12,10 +12,7 @@
1212
import javax.servlet.annotation.WebFilter;
1313
import javax.servlet.http.HttpServletRequest;
1414

15-
import org.slf4j.MDC;
16-
1715
import com.google.common.flogger.MetadataKey;
18-
import com.google.common.flogger.context.ScopedLoggingContext;
1916
import com.google.common.flogger.context.ScopedLoggingContexts;
2017

2118
@WebFilter("/*")
@@ -34,36 +31,27 @@ public void doFilter(ServletRequest request, ServletResponse response, FilterCha
3431

3532
var xTraceId = httpRequest.getHeader(HEADER_TRACE_ID);
3633
String traceId = null;
37-
if (xTraceId == null || xTraceId.isBlank())
38-
{
34+
if (xTraceId == null || xTraceId.isBlank()) {
3935
traceId = UUID.randomUUID().toString();
40-
}
41-
else
42-
{
36+
} else {
4337
traceId = validate(xTraceId); //well that needs some validation.
4438
}
45-
try (var idContext = MDC.putCloseable("traceId", traceId)) {
46-
chain.doFilter(httpRequest, response);
47-
}
48-
// ScopedLoggingContexts.newContext()
49-
// .withMetadata(MetadataKey.single("traceId", String.class), traceId)
50-
// .callUnchecked(() -> {
51-
// chain.doFilter(httpRequest, response);
52-
// return null;
53-
// });
39+
ScopedLoggingContexts.newContext()
40+
.withMetadata(MetadataKey.single("traceId", String.class), traceId)
41+
.callUnchecked(() -> {
42+
chain.doFilter(httpRequest, response);
43+
return null;
44+
});
5445
} else {
5546
chain.doFilter(request, response);
5647
}
5748
}
5849

5950
private static String validate(String id) throws IOException
6051
{
61-
if (UUID_MATCHER.matcher(id).matches())
62-
{
52+
if (UUID_MATCHER.matcher(id).matches()) {
6353
return id;
64-
}
65-
else
66-
{
54+
} else {
6755
throw new IOException("Trace id '" + id + "' is not a valid UUIDish value.");
6856
}
6957
}

‎cwms-data-api/src/test/java/cwms/cda/api/rating/RatingSpecControllerTestIT.java‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,7 @@
3939
import cwms.cda.data.dto.rating.RatingSpec;
4040
import cwms.cda.formatters.ContentType;
4141
import cwms.cda.formatters.Formats;
42+
import cwms.cda.logging.TraceIdFilter;
4243

4344
import javax.servlet.http.HttpServletResponse;
4445
import java.util.stream.IntStream;
@@ -58,6 +59,7 @@ class RatingSpecControllerTestIT extends DataApiTestIT {
5859

5960
@Test
6061
void test_empty_rating_spec() throws Exception {
62+
final String TEST_TRACE_ID = "be4710da-7931-4cb9-a621-1ab46ecc1022";
6163
String locationId = "RatingSpecTestEmpty";
6264
String officeId = "SPK";
6365
createLocation(locationId, true, officeId);
@@ -77,6 +79,7 @@ void test_empty_rating_spec() throws Exception {
7779
.contentType(Formats.XMLV2)
7880
.body(templateXml)
7981
.header("Authorization", user.toHeaderValue())
82+
.header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID)
8083
.queryParam(OFFICE, officeId)
8184
.when()
8285
.redirects().follow(true)
@@ -93,6 +96,7 @@ void test_empty_rating_spec() throws Exception {
9396
.contentType(Formats.XMLV2)
9497
.body(specXml)
9598
.header("Authorization", user.toHeaderValue())
99+
.header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID)
96100
.queryParam(OFFICE, officeId)
97101
.when()
98102
.redirects().follow(true)
@@ -109,6 +113,7 @@ void test_empty_rating_spec() throws Exception {
109113
Response response = given()
110114
.log().ifValidationFails(LogDetail.ALL,true)
111115
.accept(Formats.JSONV2)
116+
.header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID)
112117
.queryParam(PAGE_SIZE, 500)
113118
.when()
114119
.redirects().follow(true)
@@ -127,6 +132,7 @@ void test_empty_rating_spec() throws Exception {
127132
.log().ifValidationFails(LogDetail.ALL,true)
128133
.accept(Formats.JSONV2)
129134
.contentType(Formats.JSONV2)
135+
.header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID)
130136
.queryParam(OFFICE, officeId)
131137
.queryParam(RATING_ID_MASK, specContainer.specId)
132138
.when()
@@ -146,6 +152,7 @@ void test_empty_rating_spec() throws Exception {
146152
.accept(Formats.JSONV2)
147153
.contentType(Formats.JSONV2)
148154
.header("Authorization", user.toHeaderValue())
155+
.header(TraceIdFilter.HEADER_TRACE_ID, TEST_TRACE_ID)
149156
.queryParam(OFFICE, officeId)
150157
.queryParam(METHOD, JooqDao.DeleteMethod.DELETE_ALL)
151158
.when()

‎flogger-cda-context/build.gradle‎

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,23 @@
1+
plugins {
2+
id 'cda.java-conventions'
3+
id 'cda.deps-conventions'
4+
id 'java-library'
5+
}
6+
7+
8+
dependencies {
9+
annotationProcessor(libs.com.google.auto.service)
10+
compileOnly(libs.com.google.auto.service.annotations)
11+
api(libs.google.flogger.api)
12+
api(libs.slf4j)
13+
14+
testImplementation(libs.ch.qos.logback)
15+
testImplementation(libs.bundles.junit)
16+
testRuntimeOnly(libs.google.flogger.system.backend)
17+
testRuntimeOnly(libs.google.flogger.slf4j.backend)
18+
testRuntimeOnly(libs.junit.jupiter.engine)
19+
}
20+
21+
test {
22+
useJUnitPlatform()
23+
}

‎flogger-cda-context/src/main/java/cwms/cda/logging/CdaContextDataProvider.java‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
package cwms.cda.logging;
2+
3+
import com.google.auto.service.AutoService;
4+
import com.google.common.flogger.context.ContextDataProvider;
5+
import com.google.common.flogger.context.ScopedLoggingContext;
6+
7+
/**
8+
* Incredible simple implementation of Flogger's ContextDataProvider so that
9+
* we can manipulate the
10+
*/
11+
@AutoService(ContextDataProvider.class)
12+
public class CdaContextDataProvider extends ContextDataProvider {
13+
14+
private static final ScopedLoggingContext CONTEXT = new CdaLoggingContext();
15+
16+
@Override
17+
public ScopedLoggingContext getContextApiSingleton() {
18+
return CONTEXT;
19+
}
20+
}

‎flogger-cda-context/src/main/java/cwms/cda/logging/CdaLoggingContext.java‎

Lines changed: 83 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,83 @@
1+
package cwms.cda.logging;
2+
3+
import java.util.HashMap;
4+
import java.util.Map;
5+
6+
import org.slf4j.MDC;
7+
8+
import com.google.common.flogger.MetadataKey;
9+
import com.google.common.flogger.context.ScopeType;
10+
import com.google.common.flogger.context.ScopedLoggingContext;
11+
12+
/**
13+
* MAP Flogger Scoped MetaData to SLF4J MDC to apply to the MDC section of the JSON log.
14+
* Default implementation against JUL (with SLF4j or Flogger) will not show any MDC values.
15+
*
16+
* NOTE: This all assumes SLF4j is somewhere in the mix and used in the logging chain.
17+
*
18+
* Metadata keys and Tags are treated the same. Object::toString is used to convert everything to a string.
19+
*/
20+
public class CdaLoggingContext extends ScopedLoggingContext {
21+
public static final MetadataKey<String> TRACE_ID = MetadataKey.single("traceId", String.class);
22+
23+
@Override
24+
public Builder newContext() {
25+
return new CdaBuilder();
26+
}
27+
28+
@Override
29+
public Builder newContext(ScopeType scopeType) {
30+
return new CdaBuilder();
31+
}
32+
33+
34+
public static final class CdaBuilder extends Builder {
35+
36+
37+
private final Map<String,String> atCreationMdc;
38+
39+
public CdaBuilder() {
40+
var tmp = MDC.getCopyOfContextMap(); // get copy at time of creation of this context
41+
atCreationMdc = tmp == null ? new HashMap<>() : tmp;
42+
}
43+
44+
/**
45+
* Takes the MDC values that existed at the time of creation of this new Context
46+
* and the most recent context then adds the Metadata/Tag values that were set
47+
* on this context.
48+
*
49+
* MDC data is ThreadLocal, so the above behavior is required to allow the context to
50+
* properly propagate to threads, where are currently used in the {@see RatingMetaDataDao} (though no logging is done there)
51+
*
52+
*/
53+
@Override
54+
public LoggingContextCloseable install() {
55+
final var meta = this.getMetadata();
56+
final var currentMdc = MDC.getCopyOfContextMap();
57+
58+
atCreationMdc.putAll(atCreationMdc);
59+
MDC.setContextMap(atCreationMdc);
60+
61+
if (meta != null) {
62+
for (int i = 0; i < meta.size(); i++) {
63+
var key = meta.getKey(i);
64+
var val = meta.getValue(i);
65+
MDC.put(key.getLabel(), val.toString());
66+
}
67+
}
68+
69+
final var tags = this.getTags();
70+
if (tags != null) {
71+
tags.asMap().forEach((key, entry) -> {
72+
MDC.put(key, String.join(",", entry.stream().map(Object::toString).toList()));
73+
});
74+
}
75+
76+
// Just reset back the MDC map to whatever it was before we decided to muck with it.
77+
return () -> {
78+
MDC.clear();
79+
MDC.setContextMap(currentMdc);
80+
};
81+
}
82+
}
83+
}

0 commit comments

Comments
 (0)