From c1b295fd71573209122b2321b256675babfacc96 Mon Sep 17 00:00:00 2001 From: Jonatan Ivanov Date: Tue, 20 Jun 2023 21:35:36 -0700 Subject: [PATCH] Log correlation IDs when Micrometer tracing is being used Add support for logging correlation IDs with Logback or Log4J2 whenever Micrometer tracing is being used. The `LoggingSystemProperties` class now accepts a defualt value resolver which will be used whenever a value isn't in the environment. The `AbstractLoggingSystem` provides a resolver that supports the `logging.pattern.correlation` property and will return a value whenever `LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY` is set. Using `LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY` allows us to provide a consistent width for the correlation ID, even when it's missing from the MDC. The exact correlation pattern returned will depend on the `LoggingSytem` implementation. Currently Logback and Log4J2 are supported and both make use of a custom converter which delegates to a new `CorrelationIdFormatter` class. Closes gh-33280 --- ...ogCorrelationEnvironmentPostProcessor.java | 69 ++++++ .../main/resources/META-INF/spring.factories | 4 + ...relationEnvironmentPostProcessorTests.java | 67 ++++++ .../src/docs/asciidoc/actuator/tracing.adoc | 20 +- .../src/docs/asciidoc/features/logging.adoc | 1 + .../boot/logging/AbstractLoggingSystem.java | 33 ++- .../boot/logging/CorrelationIdFormatter.java | 199 ++++++++++++++++++ .../boot/logging/LoggingSystem.java | 10 +- .../boot/logging/LoggingSystemProperties.java | 29 ++- .../boot/logging/LoggingSystemProperty.java | 7 +- .../log4j2/CorrelationIdConverter.java | 69 ++++++ .../logging/log4j2/Log4J2LoggingSystem.java | 35 +-- .../logback/CorrelationIdConverter.java | 62 ++++++ .../logback/DefaultLogbackConfiguration.java | 6 +- .../logging/logback/LogbackLoggingSystem.java | 11 +- .../LogbackLoggingSystemProperties.java | 14 ++ .../logging/logback/LogbackRuntimeHints.java | 5 +- ...itional-spring-configuration-metadata.json | 6 + .../boot/logging/log4j2/log4j2-file.xml | 4 +- .../boot/logging/log4j2/log4j2.xml | 4 +- .../boot/logging/logback/defaults.xml | 5 +- .../LoggingApplicationListenerTests.java | 3 +- .../logging/AbstractLoggingSystemTests.java | 18 ++ .../logging/CorrelationIdFormatterTests.java | 122 +++++++++++ .../logging/LoggingSystemPropertiesTests.java | 21 ++ .../log4j2/CorrelationIdConverterTests.java | 65 ++++++ .../log4j2/Log4J2LoggingSystemTests.java | 77 ++++++- .../log4j2/TestLog4J2LoggingSystem.java | 18 +- .../logback/CorrelationIdConverterTests.java | 67 ++++++ .../logback/LogbackLoggingSystemTests.java | 87 +++++++- 30 files changed, 1087 insertions(+), 51 deletions(-) create mode 100644 spring-boot-project/spring-boot-actuator-autoconfigure/src/main/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessor.java create mode 100644 spring-boot-project/spring-boot-actuator-autoconfigure/src/test/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessorTests.java create mode 100644 spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/CorrelationIdFormatter.java create mode 100644 spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/CorrelationIdConverter.java create mode 100644 spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/CorrelationIdConverter.java create mode 100644 spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/CorrelationIdFormatterTests.java create mode 100644 spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/CorrelationIdConverterTests.java create mode 100644 spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/CorrelationIdConverterTests.java diff --git a/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessor.java b/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessor.java new file mode 100644 index 00000000000..d7e86849d05 --- /dev/null +++ b/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessor.java @@ -0,0 +1,69 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.actuate.autoconfigure.tracing; + +import org.springframework.boot.SpringApplication; +import org.springframework.boot.env.EnvironmentPostProcessor; +import org.springframework.boot.logging.LoggingSystem; +import org.springframework.core.env.ConfigurableEnvironment; +import org.springframework.core.env.Environment; +import org.springframework.core.env.PropertySource; +import org.springframework.util.ClassUtils; + +/** + * {@link EnvironmentPostProcessor} to add a {@link PropertySource} to support log + * correlation IDs when Micrometer is present. Adds support for the + * {@value LoggingSystem#EXPECT_CORRELATION_ID_PROPERTY} property by delegating to + * {@code management.tracing.enabled}. + * + * @author Jonatan Ivanov + * @author Phillip Webb + */ +class LogCorrelationEnvironmentPostProcessor implements EnvironmentPostProcessor { + + @Override + public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) { + if (ClassUtils.isPresent("io.micrometer.tracing.Tracer", application.getClassLoader())) { + environment.getPropertySources().addLast(new LogCorrelationPropertySource(this, environment)); + } + } + + /** + * Log correlation {@link PropertySource}. + */ + private static class LogCorrelationPropertySource extends PropertySource { + + private static final String NAME = "logCorrelation"; + + private final Environment environment; + + LogCorrelationPropertySource(Object source, Environment environment) { + super(NAME, source); + this.environment = environment; + } + + @Override + public Object getProperty(String name) { + if (name.equals(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY)) { + return this.environment.getProperty("management.tracing.enabled", Boolean.class, Boolean.TRUE); + } + return null; + } + + } + +} diff --git a/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/resources/META-INF/spring.factories b/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/resources/META-INF/spring.factories index 7d4fdd7b405..eb43227d975 100644 --- a/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/resources/META-INF/spring.factories +++ b/spring-boot-project/spring-boot-actuator-autoconfigure/src/main/resources/META-INF/spring.factories @@ -1,3 +1,7 @@ # Failure Analyzers org.springframework.boot.diagnostics.FailureAnalyzer=\ org.springframework.boot.actuate.autoconfigure.metrics.ValidationFailureAnalyzer + +# Environment Post Processors +org.springframework.boot.env.EnvironmentPostProcessor=\ +org.springframework.boot.actuate.autoconfigure.tracing.LogCorrelationEnvironmentPostProcessor diff --git a/spring-boot-project/spring-boot-actuator-autoconfigure/src/test/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessorTests.java b/spring-boot-project/spring-boot-actuator-autoconfigure/src/test/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessorTests.java new file mode 100644 index 00000000000..a75a91a28bd --- /dev/null +++ b/spring-boot-project/spring-boot-actuator-autoconfigure/src/test/java/org/springframework/boot/actuate/autoconfigure/tracing/LogCorrelationEnvironmentPostProcessorTests.java @@ -0,0 +1,67 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.actuate.autoconfigure.tracing; + +import org.junit.jupiter.api.Test; + +import org.springframework.boot.SpringApplication; +import org.springframework.boot.logging.LoggingSystem; +import org.springframework.boot.test.util.TestPropertyValues; +import org.springframework.boot.testsupport.classpath.ClassPathExclusions; +import org.springframework.core.env.ConfigurableEnvironment; +import org.springframework.core.env.StandardEnvironment; + +import static org.assertj.core.api.Assertions.assertThat; + +/** + * Tests for {@link LogCorrelationEnvironmentPostProcessor}. + * + * @author Jonatan Ivanov + * @author Phillip Webb + */ +class LogCorrelationEnvironmentPostProcessorTests { + + private final ConfigurableEnvironment environment = new StandardEnvironment(); + + private final SpringApplication application = new SpringApplication(); + + private final LogCorrelationEnvironmentPostProcessor postProcessor = new LogCorrelationEnvironmentPostProcessor(); + + @Test + void getExpectCorrelationIdPropertyWhenMicrometerPresentReturnsTrue() { + this.postProcessor.postProcessEnvironment(this.environment, this.application); + assertThat(this.environment.getProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, Boolean.class, false)) + .isTrue(); + } + + @Test + @ClassPathExclusions("micrometer-tracing-*.jar") + void getExpectCorrelationIdPropertyWhenMicrometerMissingReturnsFalse() { + this.postProcessor.postProcessEnvironment(this.environment, this.application); + assertThat(this.environment.getProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, Boolean.class, false)) + .isFalse(); + } + + @Test + void getExpectCorrelationIdPropertyWhenTracingDisabledReturnsFalse() { + TestPropertyValues.of("management.tracing.enabled=false").applyTo(this.environment); + this.postProcessor.postProcessEnvironment(this.environment, this.application); + assertThat(this.environment.getProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, Boolean.class, false)) + .isFalse(); + } + +} diff --git a/spring-boot-project/spring-boot-docs/src/docs/asciidoc/actuator/tracing.adoc b/spring-boot-project/spring-boot-docs/src/docs/asciidoc/actuator/tracing.adoc index 650b7efe249..0b9378d1acd 100644 --- a/spring-boot-project/spring-boot-docs/src/docs/asciidoc/actuator/tracing.adoc +++ b/spring-boot-project/spring-boot-docs/src/docs/asciidoc/actuator/tracing.adoc @@ -65,7 +65,25 @@ Now open the Zipkin UI at `http://localhost:9411` and press the "Run Query" butt You should see one trace. Press the "Show" button to see the details of that trace. -TIP: You can include the current trace and span id in the logs by setting the `logging.pattern.level` property to `%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]` + + +[[actuator.micrometer-tracing.logging]] +=== Logging Correlation IDs +Correlation IDs provide a helpful way to link lines in your log files to distributed traces. +By default, as long as configprop:management.tracing.enabled[] has not been set to `false`, Spring Boot will include correlation IDs in your logs whenever you are using Micrometer tracing. + +The default correlation ID is built from `traceId` and `spanId` https://logback.qos.ch/manual/mdc.html[MDC] values. +For example, if Micrometer tracing has added an MDC `traceId` of `803B448A0489F84084905D3093480352` and an MDC `spanId` of `3425F23BB2432450` the log output will include the correlation ID `[803B448A0489F84084905D3093480352-3425F23BB2432450]`. + +If you prefer to use a different format for your correlation ID, you can use the configprop:logging.pattern.correlation[] property to define one. +For example, the following will provide a correlation ID for Logback in format previously used by Spring Sleuth: + +[source,yaml,indent=0,subs="verbatim",configprops,configblocks] +---- + logging: + pattern: + correlation: "[${spring.application.name:},%X{traceId:-},%X{spanId:-}]" +---- diff --git a/spring-boot-project/spring-boot-docs/src/docs/asciidoc/features/logging.adoc b/spring-boot-project/spring-boot-docs/src/docs/asciidoc/features/logging.adoc index 5f36f43f630..b1d81e5ef07 100644 --- a/spring-boot-project/spring-boot-docs/src/docs/asciidoc/features/logging.adoc +++ b/spring-boot-project/spring-boot-docs/src/docs/asciidoc/features/logging.adoc @@ -32,6 +32,7 @@ The following items are output: * Process ID. * A `---` separator to distinguish the start of actual log messages. * Thread name: Enclosed in square brackets (may be truncated for console output). +* Correlation ID: If tracing is enabled (not shown in the sample above) * Logger name: This is usually the source class name (often abbreviated). * The log message. diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/AbstractLoggingSystem.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/AbstractLoggingSystem.java index 48be4c91f46..1d22b9aee8c 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/AbstractLoggingSystem.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/AbstractLoggingSystem.java @@ -1,5 +1,5 @@ /* - * Copyright 2012-2019 the original author or authors. + * Copyright 2012-2023 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -22,6 +22,7 @@ import java.util.HashMap; import java.util.LinkedHashSet; import java.util.Map; import java.util.Set; +import java.util.function.Function; import org.springframework.core.env.Environment; import org.springframework.core.io.ClassPathResource; @@ -174,7 +175,35 @@ public abstract class AbstractLoggingSystem extends LoggingSystem { } protected final void applySystemProperties(Environment environment, LogFile logFile) { - new LoggingSystemProperties(environment).apply(logFile); + new LoggingSystemProperties(environment, getDefaultValueResolver(environment), null).apply(logFile); + } + + /** + * Return the default value resolver to use when resolving system properties. + * @param environment the environment + * @return the default value resolver + * @since 3.2.0 + */ + protected Function getDefaultValueResolver(Environment environment) { + String defaultLogCorrelationPattern = getDefaultLogCorrelationPattern(); + return (name) -> { + if (StringUtils.hasLength(defaultLogCorrelationPattern) + && LoggingSystemProperty.CORRELATION_PATTERN.getApplicationPropertyName().equals(name) + && environment.getProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, Boolean.class, false)) { + return defaultLogCorrelationPattern; + } + return null; + }; + } + + /** + * Return the default log correlation pattern or {@code null} if log correlation + * patterns are not supported. + * @return the default log correlation pattern + * @since 3.2.0 + */ + protected String getDefaultLogCorrelationPattern() { + return null; } /** diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/CorrelationIdFormatter.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/CorrelationIdFormatter.java new file mode 100644 index 00000000000..5270833a6c9 --- /dev/null +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/CorrelationIdFormatter.java @@ -0,0 +1,199 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging; + +import java.io.IOException; +import java.io.UncheckedIOException; +import java.util.Arrays; +import java.util.Collection; +import java.util.Collections; +import java.util.Iterator; +import java.util.List; +import java.util.function.Function; +import java.util.function.Predicate; +import java.util.regex.Matcher; +import java.util.regex.Pattern; +import java.util.stream.Collectors; + +import org.springframework.util.Assert; +import org.springframework.util.CollectionUtils; +import org.springframework.util.StringUtils; + +/** + * Utility class that can be used to format a correlation identifier for logging based on + * w3c + * recommendations. + *

+ * The formatter can be configured with a comma-separated list of names and the expected + * length of their resolved value. Each item should be specified in the form + * {@code "(length)"}. For example, {@code "traceId(32),spanId(16)"} specifies the + * names {@code "traceId"} and {@code "spanId"} with expected lengths of {@code 32} and + * {@code 16} respectively. + *

+ * Correlation IDs are formatted as dash separated strings surrounded in square brackets. + * Formatted output is always of a fixed width and with trailing whitespace. Dashes are + * omitted of none of the named items can be resolved. + *

+ * The following example would return a formatted result of + * {@code "[01234567890123456789012345678901-0123456789012345] "}: 

+ * CorrelationIdFormatter formatter = CorrelationIdFormatter.of("traceId(32),spanId(16)");
+ * Map<String, String> mdc = Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345");
+ * return formatter.format(mdc::get);
+ *
+ *

+ * If {@link #of(String)} is called with an empty spec the {@link #DEFAULT} formatter will + * be used. + * + * @author Phillip Webb + * @since 3.2.0 + * @see #of(String) + * @see #of(Collection) + */ +public final class CorrelationIdFormatter { + + /** + * Default {@link CorrelationIdFormatter}. + */ + public static final CorrelationIdFormatter DEFAULT = CorrelationIdFormatter.of("traceId(32),spanId(16)"); + + private final List parts; + + private final String blank; + + private CorrelationIdFormatter(List parts) { + this.parts = parts; + this.blank = String.format("[%s] ", parts.stream().map(Part::blank).collect(Collectors.joining(" "))); + } + + /** + * Format a correlation from the values in the given resolver. + * @param resolver the resolver used to resolve named values + * @return a formatted correlation id + */ + public String format(Function resolver) { + StringBuilder result = new StringBuilder(); + formatTo(resolver, result); + return result.toString(); + } + + /** + * Format a correlation from the values in the given resolver and append it to the + * given {@link Appendable}. + * @param resolver the resolver used to resolve named values + * @param appendable the appendable for the formatted correlation id + */ + public void formatTo(Function resolver, Appendable appendable) { + Predicate canResolve = (part) -> StringUtils.hasLength(resolver.apply(part.name())); + try { + if (this.parts.stream().anyMatch(canResolve)) { + appendable.append("["); + for (Iterator iterator = this.parts.iterator(); iterator.hasNext();) { + appendable.append(iterator.next().resolve(resolver)); + appendable.append((!iterator.hasNext()) ? "" : "-"); + } + appendable.append("] "); + } + else { + appendable.append(this.blank); + } + } + catch (IOException ex) { + throw new UncheckedIOException(ex); + } + } + + @Override + public String toString() { + return this.parts.stream().map(Part::toString).collect(Collectors.joining(",")); + } + + /** + * Create a new {@link CorrelationIdFormatter} instance from the given specification. + * @param spec a comma separated specification + * @return a new {@link CorrelationIdFormatter} instance + */ + public static CorrelationIdFormatter of(String spec) { + try { + return (!StringUtils.hasText(spec)) ? DEFAULT : of(List.of(spec.split(","))); + } + catch (Exception ex) { + throw new IllegalStateException("Unable to parse correlation formatter spec '%s'".formatted(spec), ex); + } + } + + /** + * Create a new {@link CorrelationIdFormatter} instance from the given specification. + * @param spec a pre-separated specification + * @return a new {@link CorrelationIdFormatter} instance + */ + public static CorrelationIdFormatter of(String[] spec) { + return of((spec != null) ? Arrays.asList(spec) : Collections.emptyList()); + } + + /** + * Create a new {@link CorrelationIdFormatter} instance from the given specification. + * @param spec a pre-separated specification + * @return a new {@link CorrelationIdFormatter} instance + */ + public static CorrelationIdFormatter of(Collection spec) { + if (CollectionUtils.isEmpty(spec)) { + return DEFAULT; + } + List parts = spec.stream().map(Part::of).toList(); + return new CorrelationIdFormatter(parts); + } + + /** + * A part of the correlation id. + * + * @param name the name of the correlation part + * @param length the expected length of the correlation part + */ + static final record Part(String name, int length) { + + private static final Pattern pattern = Pattern.compile("^(.+?)\\((\\d+)\\)?$"); + + String resolve(Function resolver) { + String resolved = resolver.apply(name()); + if (resolved == null) { + return blank(); + } + int padding = length() - resolved.length(); + return resolved + " ".repeat((padding > 0) ? padding : 0); + } + + String blank() { + return " ".repeat(this.length); + } + + @Override + public String toString() { + return "%s(%s)".formatted(name(), length()); + } + + static Part of(String part) { + Matcher matcher = pattern.matcher(part.trim()); + Assert.state(matcher.matches(), () -> "Invalid specification part '%s'".formatted(part)); + String name = matcher.group(1); + int length = Integer.parseInt(matcher.group(2)); + return new Part(name, length); + } + + } + +} diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystem.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystem.java index d35b5ba4c64..1fd3a398378 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystem.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystem.java @@ -1,5 +1,5 @@ /* - * Copyright 2012-2021 the original author or authors. + * Copyright 2012-2023 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -23,6 +23,7 @@ import java.util.List; import java.util.Set; import org.springframework.core.env.ConfigurableEnvironment; +import org.springframework.core.env.Environment; import org.springframework.util.Assert; import org.springframework.util.ClassUtils; import org.springframework.util.StringUtils; @@ -58,6 +59,13 @@ public abstract class LoggingSystem { private static final LoggingSystemFactory SYSTEM_FACTORY = LoggingSystemFactory.fromSpringFactories(); + /** + * The name of an {@link Environment} property used to indicate that a correlation ID + * is expected to be logged at some point. + * @since 3.2.0 + */ + public static final String EXPECT_CORRELATION_ID_PROPERTY = "logging.expect-correlation-id"; + /** * Return the {@link LoggingSystemProperties} that should be applied. * @param environment the {@link ConfigurableEnvironment} used to obtain value diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperties.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperties.java index 456bb010d07..8b1b20f57f1 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperties.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperties.java @@ -19,6 +19,7 @@ package org.springframework.boot.logging; import java.nio.charset.Charset; import java.nio.charset.StandardCharsets; import java.util.function.BiConsumer; +import java.util.function.Function; import org.springframework.boot.system.ApplicationPid; import org.springframework.core.env.ConfigurableEnvironment; @@ -36,6 +37,7 @@ import org.springframework.util.Assert; * @author Vedran Pavic * @author Robert Thornton * @author Eddú Meléndez + * @author Jonatan Ivanov * @since 2.0.0 * @see LoggingSystemProperty */ @@ -160,6 +162,8 @@ public class LoggingSystemProperties { private final Environment environment; + private final Function defaultValueResolver; + private final BiConsumer setter; /** @@ -167,20 +171,34 @@ public class LoggingSystemProperties { * @param environment the source environment */ public LoggingSystemProperties(Environment environment) { - this(environment, systemPropertySetter); + this(environment, null); } /** * Create a new {@link LoggingSystemProperties} instance. * @param environment the source environment - * @param setter setter used to apply the property + * @param setter setter used to apply the property or {@code null} for system + * properties * @since 2.4.2 */ public LoggingSystemProperties(Environment environment, BiConsumer setter) { + this(environment, null, setter); + } + + /** + * Create a new {@link LoggingSystemProperties} instance. + * @param environment the source environment + * @param defaultValueResolver function used to resolve default values or {@code null} + * @param setter setter used to apply the property or {@code null} for system + * properties + * @since 3.2.0 + */ + public LoggingSystemProperties(Environment environment, Function defaultValueResolver, + BiConsumer setter) { Assert.notNull(environment, "Environment must not be null"); - Assert.notNull(setter, "Setter must not be null"); this.environment = environment; - this.setter = setter; + this.defaultValueResolver = (defaultValueResolver != null) ? defaultValueResolver : (name) -> null; + this.setter = (setter != null) ? setter : systemPropertySetter; } protected Charset getDefaultCharset() { @@ -219,6 +237,7 @@ public class LoggingSystemProperties { setSystemProperty(LoggingSystemProperty.FILE_PATTERN, resolver); setSystemProperty(LoggingSystemProperty.LEVEL_PATTERN, resolver); setSystemProperty(LoggingSystemProperty.DATEFORMAT_PATTERN, resolver); + setSystemProperty(LoggingSystemProperty.CORRELATION_PATTERN, resolver); if (logFile != null) { logFile.applyToSystemProperties(); } @@ -231,6 +250,7 @@ public class LoggingSystemProperties { private void setSystemProperty(LoggingSystemProperty property, PropertyResolver resolver, String defaultValue) { String value = (property.getApplicationPropertyName() != null) ? resolver.getProperty(property.getApplicationPropertyName()) : null; + value = (value != null) ? value : this.defaultValueResolver.apply(property.getApplicationPropertyName()); value = (value != null) ? value : defaultValue; setSystemProperty(property.getEnvironmentVariableName(), value); } @@ -263,6 +283,7 @@ public class LoggingSystemProperties { protected final void setSystemProperty(PropertyResolver resolver, String systemPropertyName, String propertyName, String defaultValue) { String value = resolver.getProperty(propertyName); + value = (value != null) ? value : this.defaultValueResolver.apply(systemPropertyName); value = (value != null) ? value : defaultValue; setSystemProperty(systemPropertyName, value); } diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperty.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperty.java index d6a73145318..b835feeb547 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperty.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/LoggingSystemProperty.java @@ -83,7 +83,12 @@ public enum LoggingSystemProperty { /** * Logging system property for the date-format pattern. */ - DATEFORMAT_PATTERN("LOG_DATEFORMAT_PATTERN", "logging.pattern.dateformat"); + DATEFORMAT_PATTERN("LOG_DATEFORMAT_PATTERN", "logging.pattern.dateformat"), + + /** + * Logging system property for the correlation pattern. + */ + CORRELATION_PATTERN("LOG_CORRELATION_PATTERN", "logging.pattern.correlation"); private final String environmentVariableName; diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/CorrelationIdConverter.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/CorrelationIdConverter.java new file mode 100644 index 00000000000..5dcf9195da4 --- /dev/null +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/CorrelationIdConverter.java @@ -0,0 +1,69 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging.log4j2; + +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.pattern.ConverterKeys; +import org.apache.logging.log4j.core.pattern.LogEventPatternConverter; +import org.apache.logging.log4j.core.pattern.MdcPatternConverter; +import org.apache.logging.log4j.core.pattern.PatternConverter; +import org.apache.logging.log4j.util.PerformanceSensitive; +import org.apache.logging.log4j.util.ReadOnlyStringMap; + +import org.springframework.boot.logging.CorrelationIdFormatter; +import org.springframework.util.ObjectUtils; + +/** + * Log4j2 {@link LogEventPatternConverter} to convert a {@link CorrelationIdFormatter} + * pattern into formatted output using data from the {@link LogEvent#getContextData() + * MDC}. + * + * @author Phillip Webb + * @since 3.2.0 + * @see MdcPatternConverter + */ +@Plugin(name = "CorrelationIdConverter", category = PatternConverter.CATEGORY) +@ConverterKeys("correlationId") +@PerformanceSensitive("allocation") +public final class CorrelationIdConverter extends LogEventPatternConverter { + + private final CorrelationIdFormatter formatter; + + private CorrelationIdConverter(CorrelationIdFormatter formatter) { + super("correlationId{%s}".formatted(formatter), "mdc"); + this.formatter = formatter; + } + + @Override + public void format(LogEvent event, StringBuilder toAppendTo) { + ReadOnlyStringMap contextData = event.getContextData(); + this.formatter.formatTo(contextData::getValue, toAppendTo); + } + + /** + * Factory method to create a new {@link CorrelationIdConverter}. + * @param options options, may be null or first element contains name of property to + * format. + * @return instance of PropertiesPatternConverter. + */ + public static CorrelationIdConverter newInstance(String[] options) { + String pattern = (!ObjectUtils.isEmpty(options)) ? options[0] : null; + return new CorrelationIdConverter(CorrelationIdFormatter.of(pattern)); + } + +} diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java index 1ff7c840ed0..da996bfd5c9 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystem.java @@ -249,12 +249,23 @@ public class Log4J2LoggingSystem extends AbstractLoggingSystem { @Override protected void loadDefaults(LoggingInitializationContext initializationContext, LogFile logFile) { - if (logFile != null) { - loadConfiguration(getPackagedConfigFile("log4j2-file.xml"), logFile, getOverrides(initializationContext)); - } - else { - loadConfiguration(getPackagedConfigFile("log4j2.xml"), logFile, getOverrides(initializationContext)); + String location = (logFile != null) ? getPackagedConfigFile("log4j2-file.xml") + : getPackagedConfigFile("log4j2.xml"); + load(initializationContext, location, logFile); + } + + @Override + protected void loadConfiguration(LoggingInitializationContext initializationContext, String location, + LogFile logFile) { + load(initializationContext, location, logFile); + } + + private void load(LoggingInitializationContext initializationContext, String location, LogFile logFile) { + List overrides = getOverrides(initializationContext); + if (initializationContext != null) { + applySystemProperties(initializationContext.getEnvironment(), logFile); } + loadConfiguration(location, logFile, overrides); } private List getOverrides(LoggingInitializationContext initializationContext) { @@ -263,15 +274,6 @@ public class Log4J2LoggingSystem extends AbstractLoggingSystem { return overrides.orElse(Collections.emptyList()); } - @Override - protected void loadConfiguration(LoggingInitializationContext initializationContext, String location, - LogFile logFile) { - if (initializationContext != null) { - applySystemProperties(initializationContext.getEnvironment(), logFile); - } - loadConfiguration(location, logFile, getOverrides(initializationContext)); - } - /** * Load the configuration from the given {@code location}, creating a composite using * the configuration from the given {@code overrides}. @@ -492,6 +494,11 @@ public class Log4J2LoggingSystem extends AbstractLoggingSystem { loggerContext.setExternalContext(null); } + @Override + protected String getDefaultLogCorrelationPattern() { + return "%correlationId"; + } + /** * Get the Spring {@link Environment} attached to the given {@link LoggerContext} or * {@code null} if no environment is available. diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/CorrelationIdConverter.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/CorrelationIdConverter.java new file mode 100644 index 00000000000..87b1e792b6c --- /dev/null +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/CorrelationIdConverter.java @@ -0,0 +1,62 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging.logback; + +import java.util.Map; + +import ch.qos.logback.classic.pattern.MDCConverter; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.pattern.DynamicConverter; + +import org.springframework.boot.logging.CorrelationIdFormatter; +import org.springframework.core.env.Environment; + +/** + * Logback {@link DynamicConverter} to convert a {@link CorrelationIdFormatter} pattern + * into formatted output using data from the {@link ILoggingEvent#getMDCPropertyMap() MDC} + * and {@link Environment}. + * + * @author Phillip Webb + * @since 3.2.0 + * @see MDCConverter + */ +public class CorrelationIdConverter extends DynamicConverter { + + private CorrelationIdFormatter formatter; + + @Override + public void start() { + this.formatter = CorrelationIdFormatter.of(getOptionList()); + super.start(); + } + + @Override + public void stop() { + this.formatter = null; + super.stop(); + } + + @Override + public String convert(ILoggingEvent event) { + if (this.formatter == null) { + return ""; + } + Map mdc = event.getMDCPropertyMap(); + return this.formatter.format(mdc::get); + } + +} diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java index 0329653359d..c86cd372e5f 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java @@ -43,6 +43,7 @@ import org.springframework.boot.logging.LogFile; * @author Vedran Pavic * @author Robert Thornton * @author Scott Frederick + * @author Jonatan Ivanov */ class DefaultLogbackConfiguration { @@ -68,12 +69,14 @@ class DefaultLogbackConfiguration { private void defaults(LogbackConfigurator config) { config.conversionRule("clr", ColorConverter.class); + config.conversionRule("correlationId", CorrelationIdConverter.class); config.conversionRule("wex", WhitespaceThrowableProxyConverter.class); config.conversionRule("wEx", ExtendedWhitespaceThrowableProxyConverter.class); config.getContext() .putProperty("CONSOLE_LOG_PATTERN", resolve(config, "${CONSOLE_LOG_PATTERN:-" + "%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) " - + "%clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} " + + "%clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} " + + "%clr(${LOG_CORRELATION_PATTERN:-}){faint}%clr(%-40.40logger{39}){cyan} " + "%clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}")); String defaultCharset = Charset.defaultCharset().name(); config.getContext() @@ -82,6 +85,7 @@ class DefaultLogbackConfiguration { config.getContext() .putProperty("FILE_LOG_PATTERN", resolve(config, "${FILE_LOG_PATTERN:-" + "%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%t] " + + "${LOG_CORRELATION_PATTERN:-}" + "%-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}")); config.getContext() .putProperty("FILE_LOG_CHARSET", resolve(config, "${FILE_LOG_CHARSET:-" + defaultCharset + "}")); diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java index ee31b9b07a4..6babadee524 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystem.java @@ -109,7 +109,7 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF @Override public LoggingSystemProperties getSystemProperties(ConfigurableEnvironment environment) { - return new LogbackLoggingSystemProperties(environment); + return new LogbackLoggingSystemProperties(environment, getDefaultValueResolver(environment), null); } @Override @@ -186,6 +186,7 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF if (!initializeFromAotGeneratedArtifactsIfPossible(initializationContext, logFile)) { super.initialize(initializationContext, configLocation, logFile); } + loggerContext.putObject(Environment.class.getName(), initializationContext.getEnvironment()); loggerContext.getTurboFilterList().remove(FILTER); markAsInitialized(loggerContext); if (StringUtils.hasText(System.getProperty(CONFIGURATION_FILE_PROPERTY))) { @@ -223,7 +224,8 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF } Environment environment = initializationContext.getEnvironment(); // Apply system properties directly in case the same JVM runs multiple apps - new LogbackLoggingSystemProperties(environment, context::putProperty).apply(logFile); + new LogbackLoggingSystemProperties(environment, getDefaultValueResolver(environment), context::putProperty) + .apply(logFile); LogbackConfigurator configurator = debug ? new DebugLogbackConfigurator(context) : new LogbackConfigurator(context); new DefaultLogbackConfiguration(logFile).apply(configurator); @@ -415,6 +417,11 @@ public class LogbackLoggingSystem extends AbstractLoggingSystem implements BeanF loggerContext.removeObject(LoggingSystem.class.getName()); } + @Override + protected String getDefaultLogCorrelationPattern() { + return "%correlationId"; + } + @Override public BeanFactoryInitializationAotContribution processAheadOfTime(ConfigurableListableBeanFactory beanFactory) { String key = BeanFactoryInitializationAotContribution.class.getName(); diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystemProperties.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystemProperties.java index 3b7b715e161..df821a47339 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystemProperties.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackLoggingSystemProperties.java @@ -18,6 +18,7 @@ package org.springframework.boot.logging.logback; import java.nio.charset.Charset; import java.util.function.BiConsumer; +import java.util.function.Function; import ch.qos.logback.core.util.FileSize; @@ -107,6 +108,19 @@ public class LogbackLoggingSystemProperties extends LoggingSystemProperties { super(environment, setter); } + /** + * Create a new {@link LoggingSystemProperties} instance. + * @param environment the source environment + * @param defaultValueResolver function used to resolve default values or {@code null} + * @param setter setter used to apply the property or {@code null} for system + * properties + * @since 3.2.0 + */ + public LogbackLoggingSystemProperties(Environment environment, Function defaultValueResolver, + BiConsumer setter) { + super(environment, defaultValueResolver, setter); + } + @Override protected Charset getDefaultCharset() { return Charset.defaultCharset(); diff --git a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackRuntimeHints.java b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackRuntimeHints.java index 532a2adf78d..44e50d50900 100644 --- a/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackRuntimeHints.java +++ b/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/LogbackRuntimeHints.java @@ -1,5 +1,5 @@ /* - * Copyright 2012-2022 the original author or authors. + * Copyright 2012-2023 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -59,7 +59,8 @@ class LogbackRuntimeHints implements RuntimeHintsRegistrar { private void registerHintsForSpringBootConverters(ReflectionHints reflection) { registerForPublicConstructorInvocation(reflection, ColorConverter.class, - ExtendedWhitespaceThrowableProxyConverter.class, WhitespaceThrowableProxyConverter.class); + ExtendedWhitespaceThrowableProxyConverter.class, WhitespaceThrowableProxyConverter.class, + CorrelationIdConverter.class); } private void registerForPublicConstructorInvocation(ReflectionHints reflection, Class... classes) { diff --git a/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json b/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json index 4835aa0c30a..17c21808424 100644 --- a/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json +++ b/spring-boot-project/spring-boot/src/main/resources/META-INF/additional-spring-configuration-metadata.json @@ -165,6 +165,12 @@ "sourceType": "org.springframework.boot.context.logging.LoggingApplicationListener", "defaultValue": "%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}" }, + { + "name": "logging.pattern.correlation", + "type": "java.lang.String", + "description": "Appender pattern for log correlation. Supported only with the default Logback setup.", + "sourceType": "org.springframework.boot.context.logging.LoggingApplicationListener" + }, { "name": "logging.pattern.dateformat", "type": "java.lang.String", diff --git a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2-file.xml b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2-file.xml index d7c510bb7a9..ee6812d92a6 100644 --- a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2-file.xml +++ b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2-file.xml @@ -4,8 +4,8 @@ %xwEx %5p yyyy-MM-dd'T'HH:mm:ss.SSSXXX - %clr{%d{${sys:LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${sys:LOG_LEVEL_PATTERN}} %clr{%pid}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} - %d{${sys:LOG_DATEFORMAT_PATTERN}} ${sys:LOG_LEVEL_PATTERN} %pid --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} + %clr{%d{${sys:LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${sys:LOG_LEVEL_PATTERN}} %clr{%pid}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{${sys:LOG_CORRELATION_PATTERN:-}}{faint}%clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} + %d{${sys:LOG_DATEFORMAT_PATTERN}} ${sys:LOG_LEVEL_PATTERN} %pid --- [%t] ${sys:LOG_CORRELATION_PATTERN:-}%-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} diff --git a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2.xml b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2.xml index 65f1a1b612d..de8588498e1 100644 --- a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2.xml +++ b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/log4j2/log4j2.xml @@ -4,8 +4,8 @@ %xwEx %5p yyyy-MM-dd'T'HH:mm:ss.SSSXXX - %clr{%d{${sys:LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${sys:LOG_LEVEL_PATTERN}} %clr{%pid}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} - %d{${sys:LOG_DATEFORMAT_PATTERN}} ${sys:LOG_LEVEL_PATTERN} %pid --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} + %clr{%d{${sys:LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${sys:LOG_LEVEL_PATTERN}} %clr{%pid}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{${sys:LOG_CORRELATION_PATTERN:-}}{faint}%clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} + %d{${sys:LOG_DATEFORMAT_PATTERN}} ${sys:LOG_LEVEL_PATTERN} %pid --- [%t] ${sys:LOG_CORRELATION_PATTERN:-}%-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} diff --git a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml index bc2ec123819..d10022ca070 100644 --- a/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml +++ b/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/defaults.xml @@ -6,13 +6,14 @@ Default logback configuration provided for import + - + - + diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/context/logging/LoggingApplicationListenerTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/context/logging/LoggingApplicationListenerTests.java index 4bfeac36306..d422f10c49a 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/context/logging/LoggingApplicationListenerTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/context/logging/LoggingApplicationListenerTests.java @@ -92,6 +92,7 @@ import static org.assertj.core.api.Assertions.assertThatIllegalStateException; * @author Ben Hale * @author Fahim Farook * @author Eddú Meléndez + * @author Jonatan Ivanov */ @ExtendWith(OutputCaptureExtension.class) @ClassPathExclusions("log4j*.jar") @@ -467,7 +468,7 @@ class LoggingApplicationListenerTests { void systemPropertiesAreSetForLoggingConfiguration() { addPropertiesToEnvironment(this.context, "logging.exception-conversion-word=conversion", "logging.file.name=" + this.logFile, "logging.file.path=path", "logging.pattern.console=console", - "logging.pattern.file=file", "logging.pattern.level=level", + "logging.pattern.file=file", "logging.pattern.level=level", "logging.pattern.correlation=correlation", "logging.pattern.rolling-file-name=my.log.%d{yyyyMMdd}.%i.gz"); this.listener.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(getSystemProperty(LoggingSystemProperty.CONSOLE_PATTERN)).isEqualTo("console"); diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/AbstractLoggingSystemTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/AbstractLoggingSystemTests.java index c80bf5654b5..cba035869ff 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/AbstractLoggingSystemTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/AbstractLoggingSystemTests.java @@ -16,14 +16,19 @@ package org.springframework.boot.logging; +import java.io.File; import java.nio.file.Path; +import java.util.Arrays; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.io.TempDir; +import org.slf4j.MDC; import org.springframework.util.StringUtils; +import static org.assertj.core.api.Assertions.contentOf; + /** * Base for {@link LoggingSystem} tests. * @@ -41,6 +46,7 @@ public abstract class AbstractLoggingSystemTests { void configureTempDir(@TempDir Path temp) { this.originalTempDirectory = System.getProperty(JAVA_IO_TMPDIR); System.setProperty(JAVA_IO_TMPDIR, temp.toAbsolutePath().toString()); + MDC.clear(); } @AfterEach @@ -53,6 +59,7 @@ public abstract class AbstractLoggingSystemTests { for (LoggingSystemProperty property : LoggingSystemProperty.values()) { System.getProperties().remove(property.getEnvironmentVariableName()); } + MDC.clear(); } protected final String[] getSpringConfigLocations(AbstractLoggingSystem system) { @@ -79,4 +86,15 @@ public abstract class AbstractLoggingSystemTests { return path; } + protected final String getLineWithText(File file, CharSequence outputSearch) { + return getLineWithText(contentOf(file), outputSearch); + } + + protected final String getLineWithText(CharSequence output, CharSequence outputSearch) { + return Arrays.stream(output.toString().split("\\r?\\n")) + .filter((line) -> line.contains(outputSearch)) + .findFirst() + .orElse(null); + } + } diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/CorrelationIdFormatterTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/CorrelationIdFormatterTests.java new file mode 100644 index 00000000000..b34771352a4 --- /dev/null +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/CorrelationIdFormatterTests.java @@ -0,0 +1,122 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging; + +import java.util.HashMap; +import java.util.Map; + +import org.junit.jupiter.api.Test; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatIllegalStateException; + +/** + * Tests for {@link CorrelationIdFormatter}. + * + * @author Phillip Webb + */ +class CorrelationIdFormatterTests { + + @Test + void formatWithDefaultSpecWhenHasBothParts() { + Map context = new HashMap<>(); + context.put("traceId", "01234567890123456789012345678901"); + context.put("spanId", "0123456789012345"); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void formatWithDefaultSpecWhenHasNoParts() { + Map context = new HashMap<>(); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[ ] "); + } + + @Test + void formatWithDefaultSpecWhenHasOnlyFirstPart() { + Map context = new HashMap<>(); + context.put("traceId", "01234567890123456789012345678901"); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[01234567890123456789012345678901- ] "); + } + + @Test + void formatWithDefaultSpecWhenHasOnlySecondPart() { + Map context = new HashMap<>(); + context.put("spanId", "0123456789012345"); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[ -0123456789012345] "); + } + + @Test + void formatWhenPartsAreShort() { + Map context = new HashMap<>(); + context.put("traceId", "0123456789012345678901234567"); + context.put("spanId", "012345678901"); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[0123456789012345678901234567 -012345678901 ] "); + } + + @Test + void formatWhenPartsAreLong() { + Map context = new HashMap<>(); + context.put("traceId", "01234567890123456789012345678901FFFF"); + context.put("spanId", "0123456789012345FFFF"); + String formatted = CorrelationIdFormatter.DEFAULT.format(context::get); + assertThat(formatted).isEqualTo("[01234567890123456789012345678901FFFF-0123456789012345FFFF] "); + } + + @Test + void formatWithCustomSpec() { + Map context = new HashMap<>(); + context.put("a", "01234567890123456789012345678901"); + context.put("b", "0123456789012345"); + String formatted = CorrelationIdFormatter.of("a(32),b(16)").format(context::get); + assertThat(formatted).isEqualTo("[01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void formatToWithDefaultSpec() { + Map context = new HashMap<>(); + context.put("traceId", "01234567890123456789012345678901"); + context.put("spanId", "0123456789012345"); + StringBuilder formatted = new StringBuilder(); + CorrelationIdFormatter.of("").formatTo(context::get, formatted); + assertThat(formatted).hasToString("[01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void ofWhenSpecIsMalformed() { + assertThatIllegalStateException().isThrownBy(() -> CorrelationIdFormatter.of("good(12),bad")) + .withMessage("Unable to parse correlation formatter spec 'good(12),bad'") + .havingCause() + .withMessage("Invalid specification part 'bad'"); + } + + @Test + void ofWhenSpecIsEmpty() { + assertThat(CorrelationIdFormatter.of("")).isSameAs(CorrelationIdFormatter.DEFAULT); + } + + @Test + void toStringReturnsSpec() { + assertThat(CorrelationIdFormatter.DEFAULT).hasToString("traceId(32),spanId(16)"); + assertThat(CorrelationIdFormatter.of("a(32),b(16)")).hasToString("a(32),b(16)"); + } + +} diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/LoggingSystemPropertiesTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/LoggingSystemPropertiesTests.java index c374f0d31c0..0f5a3a44ceb 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/LoggingSystemPropertiesTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/LoggingSystemPropertiesTests.java @@ -18,6 +18,7 @@ package org.springframework.boot.logging; import java.util.Collections; import java.util.HashSet; +import java.util.Map; import java.util.Set; import org.junit.jupiter.api.AfterEach; @@ -36,6 +37,7 @@ import static org.assertj.core.api.Assertions.assertThat; * * @author Andy Wilkinson * @author Eddú Meléndez + * @author Jonatan Ivanov */ class LoggingSystemPropertiesTests { @@ -115,6 +117,25 @@ class LoggingSystemPropertiesTests { return System.getProperty(property.getEnvironmentVariableName()); } + @Test + void correlationPatternIsSet() { + new LoggingSystemProperties( + new MockEnvironment().withProperty("logging.pattern.correlation", "correlation pattern")) + .apply(null); + assertThat(System.getProperty(LoggingSystemProperty.CORRELATION_PATTERN.getEnvironmentVariableName())) + .isEqualTo("correlation pattern"); + } + + @Test + void defaultValueResolverIsUsed() { + MockEnvironment environment = new MockEnvironment(); + Map defaultValues = Map + .of(LoggingSystemProperty.CORRELATION_PATTERN.getApplicationPropertyName(), "default correlation pattern"); + new LoggingSystemProperties(environment, defaultValues::get, null).apply(null); + assertThat(System.getProperty(LoggingSystemProperty.CORRELATION_PATTERN.getEnvironmentVariableName())) + .isEqualTo("default correlation pattern"); + } + private Environment environment(String key, Object value) { StandardEnvironment environment = new StandardEnvironment(); environment.getPropertySources().addLast(new MapPropertySource("test", Collections.singletonMap(key, value))); diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/CorrelationIdConverterTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/CorrelationIdConverterTests.java new file mode 100644 index 00000000000..87d9b22cf3f --- /dev/null +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/CorrelationIdConverterTests.java @@ -0,0 +1,65 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging.log4j2; + +import java.util.Map; + +import org.apache.logging.log4j.core.AbstractLogEvent; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.impl.JdkMapAdapterStringMap; +import org.apache.logging.log4j.util.ReadOnlyStringMap; +import org.junit.jupiter.api.Test; + +import static org.assertj.core.api.Assertions.assertThat; + +/** + * Tests for {@link CorrelationIdConverter}. + * + * @author Phillip Webb + */ +class CorrelationIdConverterTests { + + private CorrelationIdConverter converter = CorrelationIdConverter.newInstance(null); + + private final LogEvent event = new TestLogEvent(); + + @Test + void defaultPattern() { + StringBuilder result = new StringBuilder(); + this.converter.format(this.event, result); + assertThat(result).hasToString("[01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void customPattern() { + this.converter = CorrelationIdConverter.newInstance(new String[] { "traceId(0),spanId(0)" }); + StringBuilder result = new StringBuilder(); + this.converter.format(this.event, result); + assertThat(result).hasToString("[01234567890123456789012345678901-0123456789012345] "); + } + + static class TestLogEvent extends AbstractLogEvent { + + @Override + public ReadOnlyStringMap getContextData() { + return new JdkMapAdapterStringMap( + Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + } + + } + +} diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java index a177de6bae8..ceb5b64650a 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/Log4J2LoggingSystemTests.java @@ -39,6 +39,7 @@ import org.apache.logging.log4j.core.config.ConfigurationFactory; import org.apache.logging.log4j.core.config.LoggerConfig; import org.apache.logging.log4j.core.config.Reconfigurable; import org.apache.logging.log4j.core.config.composite.CompositeConfiguration; +import org.apache.logging.log4j.core.config.plugins.util.PluginRegistry; import org.apache.logging.log4j.core.util.ShutdownCallbackRegistry; import org.apache.logging.log4j.jul.Log4jBridgeHandler; import org.apache.logging.log4j.util.PropertiesUtil; @@ -47,12 +48,15 @@ import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; +import org.slf4j.MDC; import org.springframework.boot.logging.AbstractLoggingSystemTests; +import org.springframework.boot.logging.LogFile; import org.springframework.boot.logging.LogLevel; import org.springframework.boot.logging.LoggerConfiguration; import org.springframework.boot.logging.LoggingInitializationContext; import org.springframework.boot.logging.LoggingSystem; +import org.springframework.boot.logging.LoggingSystemProperties; import org.springframework.boot.logging.LoggingSystemProperty; import org.springframework.boot.testsupport.classpath.ClassPathExclusions; import org.springframework.boot.testsupport.logging.ConfigureClasspathToPreferLog4j2; @@ -86,12 +90,11 @@ import static org.mockito.Mockito.times; @ConfigureClasspathToPreferLog4j2 class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { - private final TestLog4J2LoggingSystem loggingSystem = new TestLog4J2LoggingSystem(); + private TestLog4J2LoggingSystem loggingSystem; - private final MockEnvironment environment = new MockEnvironment(); + private MockEnvironment environment; - private final LoggingInitializationContext initializationContext = new LoggingInitializationContext( - this.environment); + private LoggingInitializationContext initializationContext; private Logger logger; @@ -99,6 +102,10 @@ class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { @BeforeEach void setup() { + PluginRegistry.getInstance().clear(); + this.loggingSystem = new TestLog4J2LoggingSystem(); + this.environment = new MockEnvironment(); + this.initializationContext = new LoggingInitializationContext(this.environment); LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false); this.configuration = loggerContext.getConfiguration(); this.loggingSystem.cleanUp(); @@ -113,6 +120,7 @@ class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { loggerContext.stop(); loggerContext.start(((Reconfigurable) this.configuration).reconfigure()); cleanUpPropertySources(); + PluginRegistry.getInstance().clear(); } @SuppressWarnings("unchecked") @@ -495,6 +503,67 @@ class Log4J2LoggingSystemTests extends AbstractLoggingSystemTests { .withMessageContaining("http has not been enabled"); } + @Test + void correlationLoggingToFileWhenExpectCorrelationIdTrueAndMdcContent() { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + new LoggingSystemProperties(this.environment).apply(); + File file = new File(tmpDir(), "log4j2-test.log"); + LogFile logFile = getLogFile(file.getPath(), null); + this.loggingSystem.setStandardConfigLocations(false); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, logFile); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(file, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdTrueAndMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + this.loggingSystem.setStandardConfigLocations(false); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdFalseAndMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "false"); + this.loggingSystem.setStandardConfigLocations(false); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")).doesNotContain("0123456789012345"); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdTrueAndNoMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + this.loggingSystem.setStandardConfigLocations(false); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [ ] "); + } + + @Test + void correlationLoggingToConsoleWhenHasCorrelationPattern(CapturedOutput output) { + this.environment.setProperty("logging.pattern.correlation", "%correlationId{spanId(0),traceId(0)}"); + this.loggingSystem.setStandardConfigLocations(false); + this.loggingSystem.beforeInitialize(); + this.loggingSystem.initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [0123456789012345-01234567890123456789012345678901] "); + } + private String getRelativeClasspathLocation(String fileName) { String defaultPath = ClassUtils.getPackageName(getClass()); defaultPath = defaultPath.replace('.', '/'); diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/TestLog4J2LoggingSystem.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/TestLog4J2LoggingSystem.java index cc945ae690a..47f746592c0 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/TestLog4J2LoggingSystem.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/log4j2/TestLog4J2LoggingSystem.java @@ -1,5 +1,5 @@ /* - * Copyright 2012-2022 the original author or authors. + * Copyright 2012-2023 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -27,6 +27,8 @@ class TestLog4J2LoggingSystem extends Log4J2LoggingSystem { private final List availableClasses = new ArrayList<>(); + private String[] standardConfigLocations; + TestLog4J2LoggingSystem() { super(TestLog4J2LoggingSystem.class.getClassLoader()); } @@ -44,4 +46,18 @@ class TestLog4J2LoggingSystem extends Log4J2LoggingSystem { Collections.addAll(this.availableClasses, classNames); } + @Override + protected String[] getStandardConfigLocations() { + return (this.standardConfigLocations != null) ? this.standardConfigLocations + : super.getStandardConfigLocations(); + } + + void setStandardConfigLocations(boolean standardConfigLocations) { + this.standardConfigLocations = (!standardConfigLocations) ? new String[0] : null; + } + + void setStandardConfigLocations(String[] standardConfigLocations) { + this.standardConfigLocations = standardConfigLocations; + } + } diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/CorrelationIdConverterTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/CorrelationIdConverterTests.java new file mode 100644 index 00000000000..061251739dc --- /dev/null +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/CorrelationIdConverterTests.java @@ -0,0 +1,67 @@ +/* + * Copyright 2012-2023 the original author or authors. + * + * 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 + * + * https://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. + */ + +package org.springframework.boot.logging.logback; + +import java.util.List; +import java.util.Map; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.LoggingEvent; +import org.junit.jupiter.api.Test; + +import static org.assertj.core.api.Assertions.assertThat; + +/** + * Tests for {@link CorrelationIdConverter}. + * + * @author Phillip Webb + */ +class CorrelationIdConverterTests { + + private final CorrelationIdConverter converter; + + private final LoggingEvent event = new LoggingEvent(); + + CorrelationIdConverterTests() { + this.converter = new CorrelationIdConverter(); + this.converter.setContext(new LoggerContext()); + } + + @Test + void defaultPattern() { + addMdcProperties(this.event); + this.converter.start(); + String converted = this.converter.convert(this.event); + this.converter.stop(); + assertThat(converted).isEqualTo("[01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void customPattern() { + this.converter.setOptionList(List.of("traceId(0)", "spanId(0)")); + addMdcProperties(this.event); + this.converter.start(); + String converted = this.converter.convert(this.event); + this.converter.stop(); + assertThat(converted).isEqualTo("[01234567890123456789012345678901-0123456789012345] "); + } + + private void addMdcProperties(LoggingEvent event) { + event.setMDCPropertyMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + } + +} diff --git a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java index 515d09a1e19..8673dbd701c 100644 --- a/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java +++ b/spring-boot-project/spring-boot/src/test/java/org/springframework/boot/logging/logback/LogbackLoggingSystemTests.java @@ -45,6 +45,7 @@ import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.slf4j.ILoggerFactory; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import org.slf4j.bridge.SLF4JBridgeHandler; import org.springframework.beans.factory.aot.BeanFactoryInitializationAotContribution; @@ -87,6 +88,7 @@ import static org.mockito.Mockito.times; * @author Robert Thornton * @author Eddú Meléndez * @author Scott Frederick + * @author Jonatan Ivanov */ @ExtendWith(OutputCaptureExtension.class) class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { @@ -547,6 +549,7 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { (field) -> expectedProperties.add((String) field.get(null)), this::isPublicStaticFinal); expectedProperties.removeAll(Arrays.asList("LOG_FILE", "LOG_PATH")); expectedProperties.add("org.jboss.logging.provider"); + expectedProperties.add("LOG_CORRELATION_PATTERN"); assertThat(properties).containsOnlyKeys(expectedProperties); assertThat(properties).containsEntry("CONSOLE_LOG_CHARSET", Charset.defaultCharset().name()); } @@ -679,8 +682,81 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { assertThat(output).contains(" elements cannot be nested within an"); } + @Test + void correlationLoggingToFileWhenExpectCorrelationIdTrueAndMdcContent() { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + File file = new File(tmpDir(), "logback-test.log"); + LogFile logFile = getLogFile(file.getPath(), null); + initialize(this.initializationContext, null, logFile); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(file, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdTrueAndMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdFalseAndMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "false"); + initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")).doesNotContain("0123456789012345"); + } + + @Test + void correlationLoggingToConsoleWhenExpectCorrelationIdTrueAndNoMdcContent(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + initialize(this.initializationContext, null, null); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [ ] "); + } + + @Test + void correlationLoggingToConsoleWhenHasCorrelationPattern(CapturedOutput output) { + this.environment.setProperty("logging.pattern.correlation", "%correlationId{spanId(0),traceId(0)}"); + initialize(this.initializationContext, null, null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [0123456789012345-01234567890123456789012345678901] "); + } + + @Test + void correlationLoggingToConsoleWhenUsingXmlConfiguration(CapturedOutput output) { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + initialize(this.initializationContext, "classpath:logback-include-base.xml", null); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(output, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + + @Test + void correlationLoggingToConsoleWhenUsingFileConfiguration() { + this.environment.setProperty(LoggingSystem.EXPECT_CORRELATION_ID_PROPERTY, "true"); + File file = new File(tmpDir(), "logback-test.log"); + LogFile logFile = getLogFile(file.getPath(), null); + initialize(this.initializationContext, "classpath:logback-include-base.xml", logFile); + MDC.setContextMap(Map.of("traceId", "01234567890123456789012345678901", "spanId", "0123456789012345")); + this.logger.info("Hello world"); + assertThat(getLineWithText(file, "Hello world")) + .contains(" [01234567890123456789012345678901-0123456789012345] "); + } + private void initialize(LoggingInitializationContext context, String configLocation, LogFile logFile) { this.loggingSystem.getSystemProperties((ConfigurableEnvironment) context.getEnvironment()).apply(logFile); + this.loggingSystem.beforeInitialize(); this.loggingSystem.initialize(context, configLocation, logFile); } @@ -702,15 +778,4 @@ class LogbackLoggingSystemTests extends AbstractLoggingSystemTests { return (SizeAndTimeBasedRollingPolicy) getFileAppender().getRollingPolicy(); } - private String getLineWithText(File file, CharSequence outputSearch) { - return getLineWithText(contentOf(file), outputSearch); - } - - private String getLineWithText(CharSequence output, CharSequence outputSearch) { - return Arrays.stream(output.toString().split("\\r?\\n")) - .filter((line) -> line.contains(outputSearch)) - .findFirst() - .orElse(null); - } - }