From e75aad44364533311e03c865bd00e95540bf5f34 Mon Sep 17 00:00:00 2001 From: Fiete Ostkamp Date: Tue, 12 Dec 2023 12:08:19 +0100 Subject: Enrich log messages with further metadata about requests This includes: - endpoint - execution time - trace id Issue-ID: PORTALNG-70 Change-Id: Ia88bce25c1b29f18e6d36d3460f0c59c3689fd44 Signed-off-by: Fiete Ostkamp --- .../preferences/PreferencesApplication.java | 3 +- .../preferences/logging/LogContextVariable.java | 40 ++++++++++ .../preferences/logging/LoggerProperties.java | 11 +++ .../preferences/logging/LoggingHelper.java | 68 ++++++++++++++++ .../logging/ReactiveRequestLoggingFilter.java | 86 ++++++++++++++++++++ .../portalng/preferences/logging/StatusCode.java | 28 +++++++ .../preferences/logging/WebExchangeUtils.java | 92 ++++++++++++++++++++++ app/src/main/resources/application.yml | 8 +- app/src/test/resources/application.yml | 6 ++ 9 files changed, 340 insertions(+), 2 deletions(-) create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/LogContextVariable.java create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/LoggerProperties.java create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/LoggingHelper.java create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/ReactiveRequestLoggingFilter.java create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/StatusCode.java create mode 100644 app/src/main/java/org/onap/portalng/preferences/logging/WebExchangeUtils.java diff --git a/app/src/main/java/org/onap/portalng/preferences/PreferencesApplication.java b/app/src/main/java/org/onap/portalng/preferences/PreferencesApplication.java index 67171cd..1bbdddf 100644 --- a/app/src/main/java/org/onap/portalng/preferences/PreferencesApplication.java +++ b/app/src/main/java/org/onap/portalng/preferences/PreferencesApplication.java @@ -21,13 +21,14 @@ package org.onap.portalng.preferences; +import org.onap.portalng.preferences.logging.LoggerProperties; import org.onap.portalng.preferences.configuration.PreferencesConfig; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.boot.context.properties.EnableConfigurationProperties; -@EnableConfigurationProperties(PreferencesConfig.class) @SpringBootApplication +@EnableConfigurationProperties({PreferencesConfig.class, LoggerProperties.class}) public class PreferencesApplication { public static void main(String[] args) { diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/LogContextVariable.java b/app/src/main/java/org/onap/portalng/preferences/logging/LogContextVariable.java new file mode 100644 index 0000000..85750ea --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/LogContextVariable.java @@ -0,0 +1,40 @@ +/* + * + * Copyright (c) 2023. Deutsche Telekom AG + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + * + * + */ + +package org.onap.portalng.preferences.logging; + +import lombok.Getter; + +@Getter +public enum LogContextVariable { + TRACE_ID("trace_id"), + STATUS("status"), + NORTHBOUND_METHOD("northbound.method"), + NORTHBOUND_URL("northbound.url"), + EXECUTION_TIME("execution.time_ms"), + HTTP_STATUS("httpStatus"); + + private final String variableName; + + LogContextVariable(String variableName) { + this.variableName = variableName; + } +} diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/LoggerProperties.java b/app/src/main/java/org/onap/portalng/preferences/logging/LoggerProperties.java new file mode 100644 index 0000000..7bcc512 --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/LoggerProperties.java @@ -0,0 +1,11 @@ +package org.onap.portalng.preferences.logging; + +import java.util.List; + +import org.springframework.boot.context.properties.ConfigurationProperties; + +@ConfigurationProperties("logger") +public record LoggerProperties( + String traceIdHeaderName, + Boolean enabled, List excludePaths) { +} \ No newline at end of file diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/LoggingHelper.java b/app/src/main/java/org/onap/portalng/preferences/logging/LoggingHelper.java new file mode 100644 index 0000000..0131ec3 --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/LoggingHelper.java @@ -0,0 +1,68 @@ +/* + * + * Copyright (c) 2023. Deutsche Telekom AG + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + * + * + */ + +package org.onap.portalng.preferences.logging; + +import lombok.AccessLevel; +import lombok.NoArgsConstructor; +import org.slf4j.Logger; +import org.slf4j.MDC; + +import java.util.Map; +import java.util.function.BiConsumer; + +@NoArgsConstructor(access = AccessLevel.PRIVATE) +public class LoggingHelper { + public static void error( + Logger logger, Map metadata, String message, Object... args) { + log(logger::error, metadata, message, args); + } + + public static void debug( + Logger logger, Map metadata, String message, Object... args) { + log(logger::debug, metadata, message, args); + } + + public static void info( + Logger logger, Map metadata, String message, Object... args) { + log(logger::info, metadata, message, args); + } + + public static void warn( + Logger logger, Map metadata, String message, Object... args) { + log(logger::warn, metadata, message, args); + } + + public static void trace( + Logger logger, Map metadata, String message, Object... args) { + log(logger::trace, metadata, message, args); + } + + private static void log( + BiConsumer logMethod, + Map metadata, + String message, + Object... args) { + metadata.forEach((variable, value) -> MDC.put(variable.getVariableName(), value)); + logMethod.accept(message, args); + MDC.clear(); + } +} diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/ReactiveRequestLoggingFilter.java b/app/src/main/java/org/onap/portalng/preferences/logging/ReactiveRequestLoggingFilter.java new file mode 100644 index 0000000..d230162 --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/ReactiveRequestLoggingFilter.java @@ -0,0 +1,86 @@ +/* + * + * Copyright (c) 2023. Deutsche Telekom AG + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + * + * + */ + +package org.onap.portalng.preferences.logging; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import org.springframework.boot.autoconfigure.condition.ConditionalOnWebApplication; +import org.springframework.stereotype.Component; +import org.springframework.web.server.ServerWebExchange; +import org.springframework.web.server.WebFilter; +import org.springframework.web.server.WebFilterChain; +import reactor.core.publisher.Mono; + +import java.time.Duration; +import java.time.LocalDateTime; + +@Slf4j +@Component +@RequiredArgsConstructor +@ConditionalOnWebApplication(type = ConditionalOnWebApplication.Type.REACTIVE) +public class ReactiveRequestLoggingFilter implements WebFilter { + + private final LoggerProperties loggerProperties; + + @Override + public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { + if (loggingDisabled(exchange)) { + return chain.filter(exchange); + } + + var logMessageMetadata = + WebExchangeUtils.getRequestMetadata(exchange, loggerProperties.traceIdHeaderName()); + + LoggingHelper.info(log, logMessageMetadata, "RECEIVED"); + + var invocationStart = LocalDateTime.now(); + return chain + .filter(exchange) + .doOnTerminate( + () -> { + logMessageMetadata.put( + LogContextVariable.STATUS, + exchange.getResponse().getStatusCode().isError() + ? StatusCode.ERROR.name() + : StatusCode.COMPLETE.name()); + logMessageMetadata.put( + LogContextVariable.HTTP_STATUS, + String.valueOf(exchange.getResponse().getStatusCode().value())); + logMessageMetadata.put( + LogContextVariable.EXECUTION_TIME, + String.valueOf( + Duration.between(invocationStart, LocalDateTime.now()).toMillis())); + }) + .doOnSuccess(res -> LoggingHelper.info(log, logMessageMetadata, "FINISHED")) + .doOnError( + ex -> LoggingHelper.warn(log, logMessageMetadata, "FAILED: {}", ex.getMessage())); + } + + private boolean loggingDisabled(ServerWebExchange exchange) { + boolean loggingDisabled = loggerProperties.enabled() == null || !loggerProperties.enabled(); + + boolean urlShouldBeSkipped = + WebExchangeUtils.matchUrlsPatternsToPath(loggerProperties.excludePaths(), exchange.getRequest().getPath().value()); + + return loggingDisabled || urlShouldBeSkipped; + } +} diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/StatusCode.java b/app/src/main/java/org/onap/portalng/preferences/logging/StatusCode.java new file mode 100644 index 0000000..c565710 --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/StatusCode.java @@ -0,0 +1,28 @@ +/* + * + * Copyright (c) 2023. Deutsche Telekom AG + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + * + * + */ + +package org.onap.portalng.preferences.logging; + +public enum StatusCode { + REQUEST, + COMPLETE, + ERROR +} diff --git a/app/src/main/java/org/onap/portalng/preferences/logging/WebExchangeUtils.java b/app/src/main/java/org/onap/portalng/preferences/logging/WebExchangeUtils.java new file mode 100644 index 0000000..6a56065 --- /dev/null +++ b/app/src/main/java/org/onap/portalng/preferences/logging/WebExchangeUtils.java @@ -0,0 +1,92 @@ +/* + * + * Copyright (c) 2023. Deutsche Telekom AG + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 + * + * + */ + +package org.onap.portalng.preferences.logging; + +import lombok.AccessLevel; +import lombok.NoArgsConstructor; +import org.springframework.util.AntPathMatcher; +import org.springframework.util.PathMatcher; +import org.springframework.web.server.ServerWebExchange; + +import java.util.EnumMap; +import java.util.List; +import java.util.Map; + +@NoArgsConstructor(access = AccessLevel.PRIVATE) +public class WebExchangeUtils { + private static final String DEFAULT_TRACE_ID = "REQUEST_ID_IS_NOT_SET"; + private static final String DEFAULT_REQUEST_URL = "REQUEST_URL_IS_ABSENT"; + private static final String DEFAULT_REQUEST_METHOD = "HTTP_METHOD_IS_ABSENT"; + + private static final PathMatcher pathMatcher = new AntPathMatcher(); + + public static String getRequestId(ServerWebExchange webExchange, String traceIdHeaderName) { + if (webExchange == null || traceIdHeaderName == null) { + return DEFAULT_TRACE_ID; + } + + var requestIdHeaders = webExchange.getRequest().getHeaders().get(traceIdHeaderName); + if (requestIdHeaders != null) { + return requestIdHeaders.stream().findAny().orElse(DEFAULT_TRACE_ID); + } else { + return DEFAULT_TRACE_ID; + } + } + + public static String getRequestUrl(ServerWebExchange webExchange) { + if (webExchange == null) { + return DEFAULT_REQUEST_URL; + } + return webExchange.getRequest().getURI().toString(); + } + + public static String getRequestHttpMethod(ServerWebExchange webExchange) { + if (webExchange == null) { + return DEFAULT_REQUEST_METHOD; + } + return webExchange.getRequest().getMethod().name(); + } + + public static boolean matchUrlPatternToPath(String pattern, String path) { + return pathMatcher.match(pattern, path); + } + + public static boolean matchUrlsPatternsToPath(List patterns, String path) { + return patterns != null + && patterns.stream().anyMatch(pathPattern -> matchUrlPatternToPath(pathPattern, path)); + } + + public static Map getRequestMetadata( + ServerWebExchange exchange, String traceIdHeaderName) { + var traceId = WebExchangeUtils.getRequestId(exchange, traceIdHeaderName); + var requestMethod = WebExchangeUtils.getRequestHttpMethod(exchange); + var requestUrl = WebExchangeUtils.getRequestUrl(exchange); + + var logMessageMetadata = new EnumMap(LogContextVariable.class); + logMessageMetadata.put(LogContextVariable.TRACE_ID, traceId); + logMessageMetadata.put(LogContextVariable.STATUS, StatusCode.REQUEST.name()); + logMessageMetadata.put(LogContextVariable.NORTHBOUND_METHOD, requestMethod); + logMessageMetadata.put(LogContextVariable.NORTHBOUND_URL, requestUrl); + + return logMessageMetadata; + } +} diff --git a/app/src/main/resources/application.yml b/app/src/main/resources/application.yml index ffe174e..75654ef 100644 --- a/app/src/main/resources/application.yml +++ b/app/src/main/resources/application.yml @@ -44,4 +44,10 @@ management: probability: 1.0 # sample every request zipkin: tracing: - endpoint: http://${COLLECTOR_HOST}:${COLLECTOR_PORT}/api/v2/spans \ No newline at end of file + endpoint: http://${COLLECTOR_HOST}:${COLLECTOR_PORT}/api/v2/spans + +logger: + traceIdHeaderName: "X-Request-Id" + enabled: true + excludePaths: + - "/actuator/**" \ No newline at end of file diff --git a/app/src/test/resources/application.yml b/app/src/test/resources/application.yml index ace8c84..7092971 100644 --- a/app/src/test/resources/application.yml +++ b/app/src/test/resources/application.yml @@ -36,3 +36,9 @@ management: enabled: true java: enabled: true + +logger: + traceIdHeaderName: "X-Request-Id" + enabled: true + excludePaths: + - "/actuator/**" \ No newline at end of file -- cgit 1.2.3-korg