乐趣区

关于云计算:Java应用日志如何与Jaeger的trace关联

jiezi

欢送拜访我的 GitHub

https://github.com/zq2599/blog_demos

内容：所有原创文章分类汇总及配套源码，波及 Java、Docker、Kubernetes、DevOPS 等；

本篇概览

  • 通过《Jaeger 开发入门 (java 版)》的实战，置信您曾经能将本人的利用接入 Jaeger，并用来跟踪定位问题了，本文将介绍 Jaeger 一个玲珑而弱小的辅助性能，用大量改变大幅度晋升定位问题的便利性：将业务日志与 Jaeger 的 trace 关联
  • 在正式开始前，咱们先来看一个具体的问题：
  • 一次 web 申请可能有多条业务日志 (log4j 或者 logback 配置的那种)，这和您写代码执行 <font color=”blue”>log.info</font> 的次数无关，假如有 10 条，那么十次申请就有一百条业务日志；
  • 通过 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 的配置文件如下，可见模板中新增了一段内容 <font color=”blue”>[user-id=%X{user-id}]</font>：
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <encoder>
            <!--%logger{10} 示意类名过长时会主动缩写 -->
            <pattern>%d{HH:mm:ss} [%thread] %-5level %logger{10} [user-id=%X{user-id}] %msg%n</pattern>
            <charset>utf-8</charset>
        </encoder>
    </appender>
  • 再来看一段日志的代码，先调用 <font color=”blue”>MDC.put</font> 办法将一个键值对写入以后线程的诊断上下文 map(diagnostic context map)，键名和下面的模板中配置的 <font color=”red”>%X{user-id}</font> 截然不同：
@GetMapping("/test")
    public void test() {MDC.put("user-id", "user-" + System.currentTimeMillis());
        log.info("this is test request");
    }
  • 当初把代码运行起来，打印日志看看，如下所示，之前模板中配置的 <font color=”red”>%X{user-id}</font> 已被替换成了 <font color=”blue”>user-1632122267618</font>，就是代码中 <font color=”green”>MDC.put</font> 设置的值：
15:17:47 [http-nio-18081-exec-6] INFO  c.b.j.c.c.HelloConsumerController [user-id=user-1632122267618] this is test request
  • 以上就是 MDC 的基本功能：对日志模板中的变量进行填充，填充的内容能够用 <font color=”blue”>MDC.put</font> 办法随便设置；
  • 此刻聪慧的您应该能猜到 jaeger 官网的计划是如何实现的了，没错，就是借助 MDC 将 trace 信息填充到日志模板中，这样每行日志都有了 trace 信息，咱们在 jaeger web 页面中感兴趣的任何一次 trace，都能找到对应的日志了

对于 Jaeger 的官网计划

  • Jaeger 的官网计划如下图所示，SDK 曾经把 <font color=”blue”>traceId</font>、<font color=”blue”>spanId</font>、<font color=”blue”>sampled</font> 写入以后线程的诊断上下文 map(diagnostic context map)，只有日志模板中配置上述三个变量，就会在所有业务日志中输入它们具体的值：

  • 看起来仿佛非常简单，那就入手编码试试吧

编码实战

  • jaeger 与 MDC 的关联只是个小性能，没必要声势浩大的新建我的项目，基于《Jaeger 开发入门 (java 版)》的代码持续开发即可，也就是说批改两个子工程 <font color=”blue”>jaeger-service-consumer</font> 和 <font color=”blue”>jaeger-service-provider</font> 的源码，让它们的业务日志打印出 Jaeger 的 trace 信息
  • 首先从 <font color=”blue”>jaeger-service-provider</font> 工程开始，减少一个规范的 logback 日志配置文件 <font color=”red”>logback.xml</font>，如下所示，日志模板中已增加了 <font color=”blue”>traceId</font>、<font color=”blue”>spanId</font>、<font color=”blue”>sampled</font> 变量：
<?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>
            <!--%logger{10} 示意类名过长时会主动缩写 -->
            <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;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class JaegerConfig {
    @Bean
    public TracerBuilderCustomizer mdcBuilderCustomizer() {
        // 1.8 新个性，函数式接口
        return builder -> builder.withScopeManager(new MDCScopeManager.Builder().build());
    }
}
  • 接下来是在业务代码中随便加几行打印日志的代码，如下图红框所示：

  • 接下来持续批改 <font color=”blue”>jaeger-service-consumer</font> 子工程，具体步骤与方才革新 <font color=”blue”>jaeger-service-provider</font> 时截然不同，就不多占用篇幅赘述了，记得在业务代码中随便加几行日志，如下图红框：

  • 开发实现，开始验证吧

验证

  • 像《Jaeger 开发入门 (java 版)》那样操作，将 <font color=”blue”>jaeger-service-consumer</font> 和 <font color=”blue”>jaeger-service-provider</font> 编译构建制作成 docker 镜像
  • 用 docker-compose 将所有服务启动，而后通过浏览器拜访 <font color=”blue”>jaeger-service-consumer</font> 的服务，多拜访几次
  • 关上 jaeger 的 web 页面，能够看到屡次申请的 trace，咱们随机抉择一个，鼠标点击下图红框中的圆点：

  • 此时会跳转到该 trace 的详情页，留神页面的 url，如下图红框，外面的 <font color=”red”>2037fe105d73f4a5</font> 就是 traceid：

  • 用 <font color=”red”>2037fe105d73f4a5</font> 搜寻 <font color=”blue”>jaeger-service-provider</font> 的日志，因为利用部署在 docker 中，咱们要用 docker log 和 grep 命令组合来过滤，如下所示，咱们代码写的日志都打印进去了，并且红框中就是 traceid 等要害信息

  • 再去查看 <font color=”blue”>jaeger-service-consumer</font> 的日志，如下图红框，本次申请相干的日志也能够通过 traceid 搜寻到：

  • 至此，本篇实战就实现了，Jaeger 的 web 页面上的任何一个 trace，当初都能轻易找到与之对应的所有业务日志，这在定位问题时几乎是锦上添花的成果，如果您的零碎用了 ELK 或者 EFK 来汇总所有分布式服务的日志，那就更高效了

你不孤独，欣宸原创一路相伴

  1. Java 系列
  2. Spring 系列
  3. Docker 系列
  4. kubernetes 系列
  5. 数据库 + 中间件系列
  6. DevOps 系列

欢送关注公众号：程序员欣宸

微信搜寻「程序员欣宸」，我是欣宸，期待与您一起畅游 Java 世界 …
https://github.com/zq2599/blog_demos

退出移动版