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

Author: jonatan-ivanov

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<Object> {
+
+		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;
+		}
+
+	}
+
+}

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

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();
+	}
+
+}

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:-}]"
+----
 
 
 

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.
 

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.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 @@ protected final String getPackagedConfigFile(String fileName) {
 	}
 
 	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<String, String> 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;
 	}
 
 	/**