From 79322e1eaabd39210dc855ca1e78f734c1790fc4 Mon Sep 17 00:00:00 2001 From: Fiete Ostkamp Date: Tue, 12 Dec 2023 11:49:43 +0100 Subject: Enrich log messages with further metadata about requests This includes: - endpoint - execution time - trace id Issue-ID: PORTALNG-69 Change-Id: I5d07c89313811875bff8c1c519464e53381b5db1 Signed-off-by: Fiete Ostkamp --- .../onap/portal/history/HistoryApplication.java | 3 +- .../history/configuration/LogInterceptor.java | 62 --------------- .../configuration/RequestIdInterceptor.java | 56 +++++++++++++ .../portal/history/logging/LogContextVariable.java | 40 ++++++++++ .../portal/history/logging/LoggerProperties.java | 11 +++ .../onap/portal/history/logging/LoggingHelper.java | 68 ++++++++++++++++ .../logging/ReactiveRequestLoggingFilter.java | 89 +++++++++++++++++++++ .../onap/portal/history/logging/StatusCode.java | 28 +++++++ .../portal/history/logging/WebExchangeUtils.java | 92 ++++++++++++++++++++++ app/src/main/resources/application.yml | 8 +- app/src/test/resources/application.yml | 6 ++ 11 files changed, 399 insertions(+), 64 deletions(-) delete mode 100644 app/src/main/java/org/onap/portal/history/configuration/LogInterceptor.java create mode 100644 app/src/main/java/org/onap/portal/history/configuration/RequestIdInterceptor.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/LogContextVariable.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/LoggerProperties.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/LoggingHelper.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/ReactiveRequestLoggingFilter.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/StatusCode.java create mode 100644 app/src/main/java/org/onap/portal/history/logging/WebExchangeUtils.java diff --git a/app/src/main/java/org/onap/portal/history/HistoryApplication.java b/app/src/main/java/org/onap/portal/history/HistoryApplication.java index 21c3c4b..307d883 100644 --- a/app/src/main/java/org/onap/portal/history/HistoryApplication.java +++ b/app/src/main/java/org/onap/portal/history/HistoryApplication.java @@ -26,12 +26,13 @@ package org.onap.portal.history; import org.onap.portal.history.configuration.HistoryConfig; +import org.onap.portal.history.logging.LoggerProperties; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.boot.context.properties.EnableConfigurationProperties; -@EnableConfigurationProperties(HistoryConfig.class) @SpringBootApplication +@EnableConfigurationProperties({HistoryConfig.class, LoggerProperties.class}) public class HistoryApplication { public static void main(String[] args) { SpringApplication.run(HistoryApplication.class, args); diff --git a/app/src/main/java/org/onap/portal/history/configuration/LogInterceptor.java b/app/src/main/java/org/onap/portal/history/configuration/LogInterceptor.java deleted file mode 100644 index 113aad8..0000000 --- a/app/src/main/java/org/onap/portal/history/configuration/LogInterceptor.java +++ /dev/null @@ -1,62 +0,0 @@ -/* - * - * Copyright (c) 2022. 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.portal.history.configuration; - -import org.onap.portal.history.util.Logger; -import org.springframework.stereotype.Component; -import org.springframework.web.filter.reactive.ServerWebExchangeContextFilter; -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.util.List; - -@Component -public class LogInterceptor implements WebFilter { - public static final String EXCHANGE_CONTEXT_ATTRIBUTE = - ServerWebExchangeContextFilter.class.getName() + ".EXCHANGE_CONTEXT"; - - public static final String X_REQUEST_ID = "X-Request-Id"; - - /** - * Override a web filter to write log entries for every request and response and add header in response with X_REQUEST_ID - */ - @Override - public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { - List xRequestIdList = exchange.getRequest().getHeaders().get(X_REQUEST_ID); - if (xRequestIdList != null && !xRequestIdList.isEmpty()) { - String xRequestId = xRequestIdList.get(0); - Logger.requestLog( xRequestId, exchange.getRequest().getMethod(), exchange.getRequest().getURI()); - - exchange.getResponse().getHeaders().add(X_REQUEST_ID, xRequestId); - exchange.getResponse().beforeCommit(() -> { - Logger.responseLog(xRequestId,exchange.getResponse().getStatusCode()); - return Mono.empty(); - }); - } - - return chain - .filter(exchange) - .contextWrite(cxt -> cxt.put(EXCHANGE_CONTEXT_ATTRIBUTE, exchange)); - } -} diff --git a/app/src/main/java/org/onap/portal/history/configuration/RequestIdInterceptor.java b/app/src/main/java/org/onap/portal/history/configuration/RequestIdInterceptor.java new file mode 100644 index 0000000..aa1fd4e --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/configuration/RequestIdInterceptor.java @@ -0,0 +1,56 @@ +/* + * + * Copyright (c) 2022. 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.portal.history.configuration; + +import org.onap.portal.history.util.Logger; +import org.springframework.stereotype.Component; +import org.springframework.web.filter.reactive.ServerWebExchangeContextFilter; +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.util.List; + +@Component +public class RequestIdInterceptor implements WebFilter { + public static final String EXCHANGE_CONTEXT_ATTRIBUTE = ServerWebExchangeContextFilter.class.getName() + + ".EXCHANGE_CONTEXT"; + + public static final String X_REQUEST_ID = "X-Request-Id"; + + /** + * Override a web filter to write log entries for every request and response and + * add header in response with X_REQUEST_ID + */ + @Override + public Mono filter(ServerWebExchange exchange, WebFilterChain chain) { + List xRequestIdList = exchange.getRequest().getHeaders().get(X_REQUEST_ID); + if (xRequestIdList != null && !xRequestIdList.isEmpty()) { + String xRequestId = xRequestIdList.get(0); + exchange.getResponse().getHeaders().add(X_REQUEST_ID, xRequestId); + } + return chain + .filter(exchange) + .contextWrite(cxt -> cxt.put(EXCHANGE_CONTEXT_ATTRIBUTE, exchange)); + } +} diff --git a/app/src/main/java/org/onap/portal/history/logging/LogContextVariable.java b/app/src/main/java/org/onap/portal/history/logging/LogContextVariable.java new file mode 100644 index 0000000..76cb29e --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/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.portal.history.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/portal/history/logging/LoggerProperties.java b/app/src/main/java/org/onap/portal/history/logging/LoggerProperties.java new file mode 100644 index 0000000..c142b4f --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/logging/LoggerProperties.java @@ -0,0 +1,11 @@ +package org.onap.portal.history.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/portal/history/logging/LoggingHelper.java b/app/src/main/java/org/onap/portal/history/logging/LoggingHelper.java new file mode 100644 index 0000000..e587959 --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/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.portal.history.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/portal/history/logging/ReactiveRequestLoggingFilter.java b/app/src/main/java/org/onap/portal/history/logging/ReactiveRequestLoggingFilter.java new file mode 100644 index 0000000..059e573 --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/logging/ReactiveRequestLoggingFilter.java @@ -0,0 +1,89 @@ +/* + * + * 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.portal.history.logging; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import org.springframework.beans.factory.annotation.Value; +import org.springframework.boot.autoconfigure.condition.ConditionalOnWebApplication; +import org.springframework.boot.context.properties.EnableConfigurationProperties; +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; +import java.util.List; + +@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/portal/history/logging/StatusCode.java b/app/src/main/java/org/onap/portal/history/logging/StatusCode.java new file mode 100644 index 0000000..1c93bd9 --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/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.portal.history.logging; + +public enum StatusCode { + REQUEST, + COMPLETE, + ERROR +} diff --git a/app/src/main/java/org/onap/portal/history/logging/WebExchangeUtils.java b/app/src/main/java/org/onap/portal/history/logging/WebExchangeUtils.java new file mode 100644 index 0000000..8efda9c --- /dev/null +++ b/app/src/main/java/org/onap/portal/history/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.portal.history.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 8d3ccde..15e8422 100644 --- a/app/src/main/resources/application.yml +++ b/app/src/main/resources/application.yml @@ -46,4 +46,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 db0d057..b163059 100644 --- a/app/src/test/resources/application.yml +++ b/app/src/test/resources/application.yml @@ -38,3 +38,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