From f77bcdd6e3b54e680d8fda7113a4f66f3a2b560b Mon Sep 17 00:00:00 2001 From: Michal Somora Date: Tue, 14 Nov 2023 14:45:00 +0100 Subject: [PATCH] response status --- extensions/log/rs/README.md | 10 ++++++++-- .../log/rs/test/MdcDurationServiceTest.java | 2 +- .../log/rs/RestClientLogInterceptor.java | 5 ++++- .../log/rs/RestInterceptorContext.java | 5 +---- .../quarkus/log/rs/RestLogInterceptor.java | 9 +++++++-- .../quarkus/log/rs/RestRuntimeConfig.java | 20 +++++++++++++++---- 6 files changed, 37 insertions(+), 14 deletions(-) diff --git a/extensions/log/rs/README.md b/extensions/log/rs/README.md index 880133d..bb59dea 100644 --- a/extensions/log/rs/README.md +++ b/extensions/log/rs/README.md @@ -28,12 +28,18 @@ tkit.log.rs.start.template=%1$s %2$s started. tkit.log.rs.end.enabled=true # End log message template (%1 - HTTP method, %2 - Path, %3 - Duration, %4 - HTTP response code, %5 - HTTP response name, %6 - URI) tkit.log.rs.end.template=%1$s %2$s [%4$s] [%3$ss] -# Enable duration time as MDC parameter -tkit.log.rs.end.mdc.duration.enabled=true +# Enable MDC parameters in rest calls +tkit.log.rs.end.mdc.enabled=true # MDC duration name tkit.log.rs.end.mdc.duration.name=rs-time +# Response status MDC key name +tkit.log.rs.end.mdc.response-status.name=rs-status +# Enable MDC parameters in rest client calls +tkit.log.rs.client.end.mdc.enabled=true # MDC duration name tkit.log.rs.client.end.mdc.duration.name=rs-client-time +# Response client status MDC key name +tkit.log.rs.client.end.mdc.response-status.name=rs-client-status # Enable or disable error log message tkit.log.rs.error.enabled=true # Enable or disable error log message diff --git a/extensions/log/rs/deployment/src/test/java/org/tkit/quarkus/log/rs/test/MdcDurationServiceTest.java b/extensions/log/rs/deployment/src/test/java/org/tkit/quarkus/log/rs/test/MdcDurationServiceTest.java index 3df41b2..3faf7aa 100644 --- a/extensions/log/rs/deployment/src/test/java/org/tkit/quarkus/log/rs/test/MdcDurationServiceTest.java +++ b/extensions/log/rs/deployment/src/test/java/org/tkit/quarkus/log/rs/test/MdcDurationServiceTest.java @@ -27,6 +27,6 @@ public void mdcTest() { assertLogs().assertLines(1) .assertMatches(0, - ".+INFO \\{X-Correlation-ID=.+, rs-time=.+\\} \\[org\\.tki\\.qua\\.log\\.rs\\.tes\\.app\\.NoAnnotationRestController\\] \\(executor-thread-0\\) GET \\/no-anno\\/test1 \\[200\\] \\[.+s\\]"); + ".+INFO \\{X-Correlation-ID=.+, rs-status=200, rs-time=.+\\} \\[org\\.tki\\.qua\\.log\\.rs\\.tes\\.app\\.NoAnnotationRestController\\] \\(executor-thread-0\\) GET \\/no-anno\\/test1 \\[200\\] \\[.+s\\]"); } } diff --git a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestClientLogInterceptor.java b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestClientLogInterceptor.java index 77c64ad..7070b4f 100644 --- a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestClientLogInterceptor.java +++ b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestClientLogInterceptor.java @@ -91,9 +91,12 @@ public void filter(ClientRequestContext requestContext, ClientResponseContext re Response.StatusType status = responseContext.getStatusInfo(); context.close(); - if (config.client.end.mdc.durationEnabled) { + if (config.client.end.mdc.enabled) { MDC.put(config.client.end.mdc.durationName, context.time); context.mdcKeys.add(config.client.end.mdc.durationName); + + MDC.put(config.client.end.mdc.responseStatusName, status.getStatusCode()); + context.mdcKeys.add(config.end.mdc.responseStatusName); } if (config.client.end.enabled) { diff --git a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestInterceptorContext.java b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestInterceptorContext.java index 0cf45b8..fa0abbf 100644 --- a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestInterceptorContext.java +++ b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestInterceptorContext.java @@ -15,8 +15,6 @@ public class RestInterceptorContext { String time; - Long duration; - boolean exclude = false; Set mdcKeys = new HashSet<>(); @@ -28,7 +26,6 @@ public class RestInterceptorContext { } public void close() { - duration = (System.currentTimeMillis() - startTime); - time = String.format("%.3f", duration / 1000f); + time = String.format("%.3f", (System.currentTimeMillis() - startTime) / 1000f); } } diff --git a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestLogInterceptor.java b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestLogInterceptor.java index c25ab83..7dc7235 100644 --- a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestLogInterceptor.java +++ b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestLogInterceptor.java @@ -135,11 +135,16 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont } if (config.end.enabled && log) { - if (config.end.mdc.durationEnabled) { + Response.StatusType status = responseContext.getStatusInfo(); + + if (config.end.mdc.enabled) { MDC.put(config.end.mdc.durationName, restContext.time); restContext.mdcKeys.add(config.end.mdc.durationName); + + MDC.put(config.end.mdc.responseStatusName, status.getStatusCode()); + restContext.mdcKeys.add(config.end.mdc.responseStatusName); } - Response.StatusType status = responseContext.getStatusInfo(); + LoggerFactory.getLogger(resourceInfo.getResourceClass()) .info(String.format(config.end.template, restContext.method, restContext.path, restContext.time, status.getStatusCode(), status.getReasonPhrase(), diff --git a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestRuntimeConfig.java b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestRuntimeConfig.java index ff6ec63..8578efb 100644 --- a/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestRuntimeConfig.java +++ b/extensions/log/rs/runtime/src/main/java/org/tkit/quarkus/log/rs/RestRuntimeConfig.java @@ -220,14 +220,20 @@ public static class RestClientMdcLogConfig { /** * Enable duration time as MDC parameter */ - @ConfigItem(name = "duration.enabled", defaultValue = "true") - public boolean durationEnabled; + @ConfigItem(name = "enabled", defaultValue = "true") + public boolean enabled; /** * Duration MDC key name */ @ConfigItem(name = "duration.name", defaultValue = "rs-client-time") public String durationName; + + /** + * Response client status MDC key name + */ + @ConfigItem(name = "response-status.name", defaultValue = "rs-client-status") + public String responseStatusName; } @ConfigGroup @@ -236,14 +242,20 @@ public static class RestMdcLogConfig { /** * Enable duration time as MDC parameter */ - @ConfigItem(name = "duration.enabled", defaultValue = "true") - public boolean durationEnabled; + @ConfigItem(name = "enabled", defaultValue = "true") + public boolean enabled; /** * Duration MDC key name */ @ConfigItem(name = "duration.name", defaultValue = "rs-time") public String durationName; + + /** + * Response status MDC key name + */ + @ConfigItem(name = "response-status.name", defaultValue = "rs-status") + public String responseStatusName; } /**