Sleuth overrides a user's logging.pattern.level when it's configured in bootstrap.yml

[wilkinsona]

Describe the bug
Sleuth's default logging.pattern.level should not apply when the user has configured their own, however it is taking precedence when the user has configured their own in bootstrap.yml. Please see spring-projects/spring-boot#25418 for details. I'm not sure if this is a Sleuth problem or a more general Spring Cloud Commons problem.

Sample
There's a sample in the Spring Boot issue along with some initial analysis.

[marcingrzejszczak]

My understanding was that the Sleuth's environment post processor was adding the default at the end of all property sources cc @dsyer (https://github.com/spring-cloud/spring-cloud-sleuth/blob/master/spring-cloud-sleuth-autoconfigure/src/main/java/org/springframework/cloud/sleuth/autoconfig/TraceEnvironmentPostProcessor.java#L46-L50).

Which means that the client could override it by simply providing property of their own.

[wilkinsona]

Yeah, that seems to be what happens but the ordering is then changed later on such that bootstrap.yml ends up going after it. I'm not sure if that's because Sleuth's environment post processor is being called to soon or if the subsequent reordering is messing things up.

[marcingrzejszczak]

Interesting... Do we have any idea when this stopped happening? Is it a problem in the latest boot too (where bootstrap.yml is no longer a thing) ?

[marcingrzejszczak]

Oh I see the analysis - spring-projects/spring-boot#25418 (comment) - I'll go through it

[marcingrzejszczak]

In general in Spring Cloud 2020.x the bootstrap.yml approach is deprecated. We suggest removing bootstrap.yml, moving its contents to application.yml, providing the proper setup for spring.import.configand removing theorg.springframework.cloud:spring-cloud-starter-bootstrap` dependency.

spring:
  config:
    import: 'optional:configserver:'

spring.application.name: spring-logging-sleuth-override

logging.pattern.level: '%clr(%5p) %clr([traceid=%X{traceId:-} spanid=%X{spanId:-} parentspanid=%X{parentId:-}]){green}'

As for the Sleuth code - it was written years ago and hasn't changed at all. We're adding our map with the default logging pattern at the end of all property sources

private void addOrReplace(MutablePropertySources propertySources, Map<String, Object> map) {
		MapPropertySource target = null;
		if (propertySources.contains(PROPERTY_SOURCE_NAME)) {
			PropertySource<?> source = propertySources.get(PROPERTY_SOURCE_NAME);
			if (source instanceof MapPropertySource) {
				target = (MapPropertySource) source;
				for (String key : map.keySet()) {
					if (!target.containsProperty(key)) {
						target.getSource().put(key, map.get(key));
					}
				}
			}
		}
		if (target == null) {
			target = new MapPropertySource(PROPERTY_SOURCE_NAME, map);
		}
		if (!propertySources.contains(PROPERTY_SOURCE_NAME)) {
			propertySources.addLast(target);
		}
	}

We're inserting ourselves last. I even ensured that the TraceEnvironmentPostProcessor is Ordered and with min order. I think there must be some issue either in Boot. It works well for the legacy Bootstrap context

2021-03-16 13:58:10.817  INFO [traceid= spanid= parentspanid=] 58189 --- [           main] c.c.c.ConfigServicePropertySourceLocator : Fetching config from server at : http://localhost:8888
2021-03-16 13:58:10.945  INFO [traceid= spanid= parentspanid=] 58189 --- [           main] c.c.c.ConfigServicePropertySourceLocator : Located environment: name=spring-logging-sleuth-overrideasdasd, profiles=[default], label=null, version=null, state=null
2021-03-16 13:58:10.946  INFO [traceid= spanid= parentspanid=] 58189 --- [           main] b.c.PropertySourceBootstrapConfiguration : Located property source: [BootstrapPropertySource {name='bootstrapProperties-configClient'}]

it stops working well for the actual context

2021-03-16 13:58:10.946  INFO [traceid= spanid= parentspanid=] 58189 --- [           main] b.c.PropertySourceBootstrapConfiguration : Located property source: [BootstrapPropertySource {name='bootstrapProperties-configClient'}]
2021-03-16 13:58:10.955  INFO [spring-logging-sleuth-override,,] 58189 --- [           main] c.g.a.s.app.MyAwesomeApplication         : No active profile set, falling back to default profiles: default
2021-03-16 13:58:11.535  INFO [spring-logging-sleuth-override,,] 58189 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=bcc154e2-24d5-3a77-812c-ec08a5e3250f

[spring-cloud-issues]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[wilkinsona]

I'm not sure what feedback you're waiting for here. As we discussed on Slack, I'm not sure that this has ever worked. I went as far back as Spring Boot 2.2.0 and it didn't look like the property source ended up in the right place once all the bootstrap stuff had settled down.

@artemy Is switching from the bootstrap context to a spring.config.import as @marcingrzejszczak suggests above an option for you?

[artemy]

@wilkinsona thanks for the investigation. Yes, using spring.config.import would work

[marcingrzejszczak]

I'm closing this issue with the note that the correct way to go is to use spring.config.import

[wilkinsona]

What about users of Spring Boot 2.3 where spring.config.import isn't an option?

[marcingrzejszczak]

I've added a parameter spring.sleuth.default-logging-pattern-enabled which is turned on by default. By setting it to false the default Sleuth pattern will not be set.

[spicalous]

Hi @marcingrzejszczak,

I can see this spring.sleuth.default-logging-pattern-enabled is available in 2.2

Was there a reason this was not ported to v3.x?

[marcingrzejszczak]

Yes, because starting from Sleuth 3.x you should not be using bootstrap.yml anymore.

[spicalous]

Thanks for the prompt response!

We're not using bootstrap.yml in our app, but we are specifying in our application.yml something like

logging.config: path/to/logback.xml

see https://docs.spring.io/spring-boot/docs/current/reference/html/features.html#features.logging.custom-log-configuration

Is this a valid case to port the default-logging-pattern-enabled flag to v3 where we do not want our logging pattern to be overridden by spring-cloud-sleuth?

[marcingrzejszczak]

The thing is that your stuff should not be overridden by what Sleuth does. Can you create a small reproducer for this?

[spicalous]

@marcingrzejszczak Created a minimal reproduction repo

https://github.com/spicalous/sleuth-override-example

[spicalous]

@marcingrzejszczak

I've raised a PR to reintroduce the configuration back #2196

Please let me know your thoughts :)