spring cloud sleuth 自定义traceId, spanId日志pattern

spring cloud sleuth 默认情况下会将traceId 和 spanId 写到MDC里面, 然后根据配置的pattern会将这两个值写到日志文件或者console里面. 但是如果此时自己的业务逻辑中也需要往MDC里面写入数据,然后写到日志文件. 比如业务中需要将aId 和 bId 两个属性写入MDC, 想将traceId, spanId 和业务aid和bid都保存在日志中, 一般做法就想到的就是去配置logging pattern如下:

logging:
	pattern:
		console: '%d{yyyy-MMM-dd HH:mm:ss.SSS} %-5level [%X{aid:-}, %X{bId:-}, %X{traceId:-},%X{spanId:-}][%thread] %logger{15} - %msg%n'

可以看到此pattern种MDC中的数据aid, bid, traceId, spanId都会打印出来,
其中的%X 就是从MDC中取出字段放入日志. 但是运行起来,输出结果就会出现traceId和spanId 被重复记录的情况, 结果模式如下:

[traceId, spanid] [aid, bid, traceId, spanid]

由此可以推断前一个方框中的数据(traceId, spanId) 是sleuth默认情况下会在日志中append 的, 现在需要去除这一部分内容, 因为两个id我们已经用自己的pattern获取了. 本文就讨论一下如何改变sleuth的默认的pattern. 将其灵活的和业务的MDC数据字段一起放在日志中.

这里需要提到sleuth 中的一个类 org.springframework.cloud.sleuth.autoconfig.TraceEnvironmentPostProcessor
察看这个类源码

/*
 * Copyright 2013-2020 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.cloud.sleuth.autoconfig;

import java.util.HashMap;
import java.util.Map;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.env.EnvironmentPostProcessor;
import org.springframework.core.env.ConfigurableEnvironment;
import org.springframework.core.env.MapPropertySource;
import org.springframework.core.env.MutablePropertySources;
import org.springframework.core.env.PropertySource;

/**
 * Adds default properties for the application: logging pattern level that prints trace
 * information (e.g. trace ids).
 *
 * @author Dave Syer
 * @author Marcin Grzejszczak
 * @since 2.0.0
 */
class TraceEnvironmentPostProcessor implements EnvironmentPostProcessor {

	private static final String PROPERTY_SOURCE_NAME = "defaultProperties";

	@Override
	public void postProcessEnvironment(ConfigurableEnvironment environment, SpringApplication application) {
		Map<String, Object> map = new HashMap<String, Object>();
		// This doesn't work with all logging systems but it's a useful default so you see
		// traces in logs without having to configure it.
		if (Boolean.parseBoolean(environment.getProperty("spring.sleuth.enabled", "true"))) {
			map.put("logging.pattern.level",
					"%5p [${spring.zipkin.service.name:" + "${spring.application.name:}},%X{traceId:-},%X{spanId:-}]");
		}
		addOrReplace(environment.getPropertySources(), map);
	}

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

}

关键的一行代码

map.put("logging.pattern.level",
					"%5p [${spring.zipkin.service.name:" + "${spring.application.name:}},%X{traceId:-},%X{spanId:-}]");

这里当sleuth被enable的时候会添加logging.pattern.level 这个配置, 然后把sleuth相关的traceId和spanId增加到pattern里面. 也就是这行代码,让我们从日志中看到了多出的第一个方框的traceId和spanId. spring boot 的 meta data 有对这个配置做描述.

 {
      "name": "logging.pattern.level",
      "type": "java.lang.String",
      "description": "Appender pattern for log level. Supported only with the default Logback setup.",
      "sourceType": "org.springframework.boot.context.logging.LoggingApplicationListener",
      "defaultValue": "%5p"
    }

可以理解为这个配置就是追加pattern到已经存在的pattern里面, 所以会默认输出traceId和spanId. 此pattern的默认值是%5p, 只需要在自己的程序配置文件中显示配置这个值覆盖掉TraceEnvironmentPostProcessor 中指定的值即可.

logging:
	pattern:
		level: '%5p'

然后最终日志输出, 即可解决问题:

[aid, bid, traceId, spanid]

其实这个问题,sleuth官方文档有提到过.
sleuth logging integration

Above, you’ll notice the trace ID is 5e8eeec48b08e26882aba313eb08f0a4, for example. This log configuration was automatically setup by Sleuth. You can disable it by disabling Sleuth via spring.sleuth.enabled=false property or putting your own logging.pattern.level property.

可以使用自定义的pattern去覆盖掉sleuth默认的pattern实现自定义pattern.