写点什么

Java 应用日志如何与 Jaeger 的 trace 关联,腾讯、字节跳动面经已发

作者:Java高工P7
  • 2021 年 11 月 10 日
  • 本文字数:1907 字

    阅读完需:约 6 分钟

这里分类和汇总了欣宸的全部原创(含配套源码):https://github.com/zq2599/blog_demos

本篇概览

  • 经过《Jaeger开发入门(java版)》的实战,相信您已经能将自己的应用接入 Jaeger,并用来跟踪定位问题了,本文将介绍 Jaeger 一个小巧而强大的辅助功能,用少量改动大幅度提升定位问题的便利性:将业务日志与 Jaeger 的 trace 关联

  • 在正式开始前,咱们先来看一个具体的问题:


  1. 一次 web 请求可能有多条业务日志(log4j 或者 logback 配置的那种),这和您写代码执行 log.info 的次数有关,假设有 10 条,那么十次请求就有一百条业务日志;

  2. 通过 jaeger 发现这十次请求中有一次耗时特别长,想定位一下具体原因,现在问题来了:一共有 100 条业务日志,到底哪些是和 Jaeger 中耗时长的那一次请求有关?


  • 您可能会说:有些业务特征如 user-id,咱们可以写入 span 的 tag 或者 log 中,这样通过 span 查到 user-id,再去日志中查找含有此 user-id 的日志即可,这样确实可以,但未必每条日志都有 user-id,所以并非最佳方式

  • 好在 Jaeger 官方给出了一种简单有效的方案:基于 MDC,Jaeger 的 SDK 在日志中注入 trace 相关的变量

关于 MDC

  • 关于 sl4j 的 MDC 不是本篇的重点,因此只把本篇用到的特性简单说说即可,经验丰富的您如果对 MDC 已经了解,请跳过此节

  • 在 sl4j 的配置文件中可以配置日志的格式,例如 logback 的配置文件如下,


《Android学习笔记总结+最新移动架构视频+大厂安卓面试真题+项目实战源码讲义》
浏览器打开:qq.cn.hn/FTe 免费领取
复制代码


可见模板中新增了一段内容[user-id=%X{user-id}]:


<appender name="console" class="ch.qos.logback.core.ConsoleAppender">


<filter class="ch.qos.logback.classic.filter.ThresholdFilter">


<level>INFO</level>


</filter>


<encoder>


<pattern>%d{HH:mm:ss} [%thread] %-5level %logger{10} [user-id=%X{user-id}] %msg%n</pattern>


<charset>utf-8</charset>


</encoder>


</appender>


  • 再来看一段日志的代码,先调用 MDC.put 方法将一个键值对写入当前线程的诊断上下文 map(diagnostic context map),键名和上面的模板中配置的**%X{user-id}**一模一样:


@GetMapping("/test")


public void test() {


MDC.put("user-id", "user-" + System.currentTimeMillis());


log.info("this is test request");


}


  • 现在把代码运行起来,打印日志看看,如下所示,之前模板中配置的**%X{user-id}**已被替换成了 user-1632122267618,就是代码中 MDC.put 设置的值:


15:17:47 [http-nio-18081-exec-6] INFO c.b.j.c.c.HelloConsumerController [user-id=user-1632122267618] this is test request


  • 以上就是 MDC 的基本功能:对日志模板中的变量进行填充,填充的内容可以用 MDC.put 方法随意设置;

  • 此刻聪明的您应该能猜到 jaeger 官方的方案是如何实现的了,没错,就是借助 MDC 将 trace 信息填充到日志模板中,这样每行日志都有了 trace 信息,咱们在 jaeger web 页面中感兴趣的任何一次 trace,都能找到对应的日志了

关于 Jaeger 的官方方案

  • Jaeger 的官方方案如下图所示,SDK 已经把 traceId、spanId、sampled 写入当前线程的诊断上下文 map(diagnostic context map),只要日志模板中配置上述三个变量,就会在所有业务日志中输出它们具体的值:



  • 看起来似乎非常简单,那就动手编码试试吧

编码实战

  • jaeger 与 MDC 的关联只是个小功能,没必要大张旗鼓的新建项目,基于《Jaeger开发入门(java版)》的代码继续开发即可,也就是说修改两个子工程 jaeger-service-consumer 和 jaeger-service-provider 的源码,让它们的业务日志打印出 Jaeger 的 trace 信息

  • 首先从 jaeger-service-provider 工程开始,增加一个标准的 logback 日志配置文件 logback.xml,如下所示,日志模板中已添加了 traceId、spanId、sampled 变量:


<?xml version="1.0" encoding="UTF-8"?>


<configuration scan="true" scanPeriod="60 seconds" debug="false">


<contextName>logback</contextName>


<appender name="console" class="ch.qos.logback.core.ConsoleAppender">


<filter class="ch.qos.logback.classic.filter.ThresholdFilter">


<level>INFO</level>


</filter>


<encoder>


<pattern>%d{HH:mm:ss} [%thread] %-5level %logger{10} [traceId=%X{traceId} spanId=%X{spanId} sampled=%X{sampled}] %msg%n</pattern>


<charset>utf-8</charset>


</encoder>


</appender>


<root level="info">


<appender-ref ref="console" />


</root>


</configuration>


  • 再去检查配置类,确认 JaegerTracer 实例化时用了 MDCScopeManager 参数,如下所示,咱们在上一章已经这么做了,可以维持不变:


package com.bolingcavalry.jaeger.provider.config;


import io.jaegertracing.internal.MDCScopeManager;


import io.opentracing.contrib.java.spring.jaeger.starter.TracerBuilderCustomizer;

用户头像

Java高工P7

关注

还未添加个人签名 2021.11.08 加入

还未添加个人简介

评论

发布
暂无评论
Java应用日志如何与Jaeger的trace关联,腾讯、字节跳动面经已发