springcloud链路监控，服务间用mq通信，日志链路MDC搞法

背景

我们目前项目的链路监控和日志收集工具都是外采的成熟产品，基于pinpoint，虽然是供应商又封装了一层，但是原理都是一样的。

日常我们项目进行链路追踪配置和日志采集很简单，springboot项目中logback增加traceId输出，jar启动是增加pinpoint探针，这样就可以了。

但是，一旦涉及到服务和服务之间通过mq进行数据交互，trace链路就断掉了，没法进行采集，于是开始各种想办法，实现了mq间的链路追踪。

基础配置

logback配置

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} - [ppTraceId:  %X{PtxId} , ppSpanId: %X{PspanId}] - [%thread] %-5level %logger{50}.%M\(%line\) - %msg%n
            </pattern>
        </encoder>
    </appender>

其中PtxId和PsanId是pinpoint设置到MDC中的变量，MDC是logback提供的工具类，详细用法大家可以百度。

jar运行脚本

java -XX:InitialRAMPercentage=70.0 -XX:MaxRAMPercentage=70.0 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heapdump.hprof -javaagent:/app/pinpoint-agent-2.0.3/pinpoint-bootstrap-2.0.3.jar -Dpinpoint.licence=test -Dpinpoint.applicationName=test -Dpinpoint.agentId=test -jar app.jar"

脚本没什么特殊的，就是为了把pinpoint探针打进去。

MQ链路日志方法

思路

logback提供了MDC，pinpoint也是把相应的trace信息放进MDC中，然后logback打印日志时就把trace信息打印出来了，那我们也按照相应的原理进行实现。

消息生产服务设置消息头

消息生产服务将当前请求的MDC中trace信息取出，放在mq的header中，不同消息中间件的实现方式不一致，大家可以自己修改。另外，我这个项目只有这一个消息通信，所以没有使用消息拦截器，最好的实现方式是实现统一的消息拦截器进行header的设置。

@Slf4j
@Service
public class TodoMessageServiceImpl{

public Result<?> todoMessageHandel(HttpServletRequest request, List<TaskIntegrationCallDTO> taskIntegrationCallList) {
        log.debug("请求放地址 ： Addr = {}，Host = {}，Port = {}", request.getRemoteAddr(), request.getRemoteHost(), request.getRemotePort());
        Result<?> result;
        String mqMsgId = null;
        PayloadDTO<List<TaskIntegrationCallDTO>> payload = this.dataHandle(taskIntegrationCallList,notBlank);
        // 如果 verify 不能等于null 证明有异常
        if (notBlank) {
            result = Result.isError(verify.getMsg(),verify.getCode());
        }else{
            try {
                log.info("traceId测试:"+MDC.get("PtxId")+","+MDC.get("PspanId"));
                Map<String, Object> messageHeaderMap = new HashMap<>();
                messageHeaderMap.put("PtxId", MDC.get("PtxId"));
                messageHeaderMap.put("PspanId", MDC.get("PspanId"));
                MessageHeaders messageHeaders = new MessageHeaders(messageHeaderMap);
                Message<PayloadDTO<List<TaskIntegrationCallDTO>>> message = MessageBuilder.createMessage(payload,messageHeaders);
                SendResult sendResult = rocketMQTemplate.syncSendOrderly(payload.getTopic(), message, payload.getProcessId());
                mqMsgId = sendResult.getOffsetMsgId();
                result = Result.isOk();
            } catch (Exception e) {
                log.error("消息发送异常 异常业务编号 = {}",payload.getProcessId(),e);
                result = Result.isError(B0000ResponseCodeEnums.B0001.getMsg(),B0000ResponseCodeEnums.B0001.getMsg());
            }
        }
        // 日志留存
        messageService.saveMessageLogHandle(request, payload, result, ElasticsearchConstant.LOG_TYPE_TODO, mqMsgId);
        return result;
    }

其中关键代码，我这里取了traceId和spanId，pinpoint中的traceId和spanId是固定值PtxId和PspanId，因为我用的pinpoint，所以直接取了，其他链路追踪工具可以自己查找相应的变量名称

log.info("traceId测试:"+MDC.get("PtxId")+","+MDC.get("PspanId"));
Map<String, Object> messageHeaderMap = new HashMap<>();
messageHeaderMap.put("PtxId", MDC.get("PtxId"));
messageHeaderMap.put("PspanId", MDC.get("PspanId"));
MessageHeaders messageHeaders = new MessageHeaders(messageHeaderMap);
Message<PayloadDTO<List<TaskIntegrationCallDTO>>> message = MessageBuilder.createMessage(payload,messageHeaders);

消息消费服务获取消息头，设置MDC

消息消费服务将当前消息的header取出，放入MDC中，值与logback日志中配置的变量保持一致。

@Slf4j
@Service
@ConditionalOnBean(RocketMQConsumerProperties.class)
public class ConsumeTodo {
@Autowired
    private RocketMQConsumerProperties rocketMQConsumerProperties;

    @Value("${rocketmq.name-server}")
    private String namesrvAddr;

    public void consumerTodoInit() {

        try {
            DefaultMQPushConsumer consumer = new DefaultMQPushConsumer(new AclClientRPCHook(
                    new SessionCredentials(rocketMQConsumerProperties.getAccessKey(), rocketMQConsumerProperties.getSecretKey())));
            consumer.setNamesrvAddr(namesrvAddr);
            consumer.setConsumerGroup(rocketMQConsumerProperties.getTodoConsumeGroup());
            consumer.setConsumeThreadMin(rocketMQConsumerProperties.getTodoConsumeThread());
            consumer.setConsumeThreadMax(rocketMQConsumerProperties.getTodoConsumeThread());
            consumer.subscribe(rocketMQConsumerProperties.getTodoTopic(), "*");
            consumer.registerMessageListener(new MessageListenerOrderly() {

                @Override
                public ConsumeOrderlyStatus consumeMessage(List<MessageExt> msgs, ConsumeOrderlyContext context) {

                    for (MessageExt msg : msgs) {
                        try {
                            String traceId = msg.getUserProperty("PtxId");
                            String spanId = msg.getUserProperty("PspanId");
                            if (traceId != null && spanId != null) {
                                log.info("消息接收traceId:"+traceId+"-----"+spanId);
                                MDC.put("PtxId", traceId);
                                MDC.put("PspanId", spanId);
                            }
                            String request = new String(msg.getBody(), Charset.defaultCharset());
                            log.debug("rockerMQ todo consume payload = {}", request);
                            // 参数转换
                            PayloadDTO<List<TaskIntegrationCall>> payload = JSONObject.parseObject(request, new TypeReference<PayloadDTO<List<TaskIntegrationCall>>>() {
                            });
                            integrationCallService.workflowIntegration(payload.getData());
                        } catch (Exception e) {
                            log.error("rockerMQ todo consume error ", e);
                        }finally {
                            MDC.clear();
                        }
                    }

                    return ConsumeOrderlyStatus.SUCCESS;
                }
            });

            consumer.start();
        } catch (Exception e) {
            log.error("rockerMQ todo start error ", e);
        }
    }

其中关键代码，从message的header中取出traceId 和spanId，设置到MDC中，但是这我碰到一个问题，MDC.put("PtxId", traceId);MDC.put("PspanId", spanId);    PtxId和PspanId参数和pinpoint冲突，这个消费消息的服务打了pinpoint探针，logback日志不能正常输出traceId，所以我消费服务把pinpoint探针删除了，其实可以设置一个其他的变量值，在logback中配置日志输出，这样就不冲突了。

String traceId = msg.getUserProperty("PtxId");
String spanId = msg.getUserProperty("PspanId");
if (traceId != null && spanId != null) {
     log.info("消息接收traceId:"+traceId+"-----"+spanId);
     MDC.put("PtxId", traceId);
     MDC.put("PspanId", spanId);
}