本文内容主要翻译(意译)自Yurishkuro大神的opentracing-tutorial java,加了一些补充说明,方便理解,习惯看英文的也可以看原文。总共4篇,本文是第2篇。如果你还没接触过OpenTracing,建议先读这篇文章《OpenTracing概念术语介绍》和官方文档

  1. 第1篇:单span的trace创建
  2. 第2篇:多span的trace创建(进程内SpanContext传递)本文)。
  3. 第3篇:跨服务(进程)传递SpanContext
  4. 第4篇:Baggage介绍

目标

学习如何:

  • 跟踪不同的函数
  • 创建一个包含多个span的链路
  • 在进程(其实是线程)内部上下文之间传递链路信息

开发步骤

说明:源代码的exercise包下面的类是空的,是留给我们按教程一步步补充完善的;solution包是已经编写好的代码。

本文基于教程1,所以先把把教程1里面solution下面的Hello.java拷贝到lesson02/exercise/Hello.java下面。

跟踪不同的函数

上篇文章的sayHello(String helloTo)方法做了两件事情:格式化输出字符串打印输出。因为在一个方法里面,所以只产生了一个span,为了演示如何产生多个san,这里我们将这个方法拆分成两个单独的函数:

String helloStr = formatString(span, helloTo);
printHello(span, helloStr);

函数体如下:

// 格式化字符串
private String formatString(Span span, String helloTo) {
    String helloStr = String.format("Hello, %s!", helloTo);
    span.log(ImmutableMap.of("event", "string-format", "value", helloStr));
    return helloStr;
}
// 打印输出
private void printHello(Span span, String helloStr) {
    System.out.println(helloStr);
    span.log(ImmutableMap.of("event", "println"));
}

然后我们再给每个函数里面加上span信息:

private  String formatString(Span rootSpan, String helloTo) {
    Span span = tracer.buildSpan("formatString").start();
    try {
        String helloStr = String.format("Hello, %s!", helloTo);
        span.log(ImmutableMap.of("event", "string-format", "value", helloStr));
        return helloStr;
    } finally {
        span.finish();
    }
}

private void printHello(Span rootSpan, String helloStr) {
    Span span = tracer.buildSpan("printHello").start();
    try {
        System.out.println(helloStr);
        span.log(ImmutableMap.of("event", "println"));
    } finally {
        span.finish();
    }
}

运行(这截取了span相关的日志信息):

-> % ./run.sh lesson02.solution.HelloManual Bryan
08:07:28.078 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: 7e2c775eb9a9ac55:7e2c775eb9a9ac55:0:1 - formatString
Hello, Bryan!
08:07:28.087 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: ab294a35b8deb4c3:ab294a35b8deb4c3:0:1 - printHello
08:07:28.087 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: 45dcde709e09015d:45dcde709e09015d:0:1 - say-hello

这里简单介绍一下Span reported:后面的输出,这里有几个使用冒号分隔的ID:

  • 第一个ID代表traceID,唯一标识一个链路;
  • 第二个是spanID,唯一标识一个span;
  • 第三个是当前span的父spanID,如果没有(即自己就是根节点),则为0。

这里的确产生了三个span,但这三个span的TraceID各不一样,也就是说这三个span分别代表一个链路,即我们创建了三个trace,每个trace包含1个span,这显然不是我们想要的,因为这里三个span是有调用关系的,它们最终应该形成一个trace,这个trace包含3个span。

lesson-02-1.png

产生这个结果的原因是tracer.buildSpan("操作名").start();会创建一个新的span,而且默认这个span就是根节点,如果需要将其作为子节点的话,需要使用ChildOf明确指出其父节点:

// formatString
Span span = tracer.buildSpan("formatString").asChildOf(rootSpan).start();
// printHello
Span span = tracer.buildSpan("printHello").asChildOf(rootSpan).start();

修改代码后,重新运行函数:

./run.sh lesson02.solution.HelloManual Bryan
08:20:56.204 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: 836db6b9e1cb6e87:159e8c7d440d171a:836db6b9e1cb6e87:1 - formatString
Hello, Bryan!
08:20:56.209 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: 836db6b9e1cb6e87:149c8f7aeadb5319:836db6b9e1cb6e87:1 - printHello
08:20:56.209 [main] INFO io.jaegertracing.internal.reporters.LoggingReporter - Span reported: 836db6b9e1cb6e87:836db6b9e1cb6e87:0:1 - say-hello

这次可以看到,三个span的traceID是一样的,说明它们三个都属于一个trace,且前两个spanID的父spanID都是最后一个,这个结果是比较符合预期的。我们再看下链路图:

lesson-02-2.png

可以看到只新产生了一个trace,且里面包含了3个span。点开这个trace:

lesson-02-3.png

从这个链路图就可以看出来函数间的调用关系,以及各个调用的耗时。如果点击每个span,还可以查看附加的一些基本信息。

至此,功能基本就完成了。美中不足的是每个函数调用都要传递父span,非常不方便,幸运的是java有thread local变量,可以使用这个机制省略掉同一个线程里面函数间的这个参数传递。代码如下:

import io.opentracing.Scope;

private void sayHello(String helloTo) {
    Span span = tracer.buildSpan("say-hello").start();
    try (Scope scope = tracer.scopeManager().activate(span)) {
        span.setTag("hello-to", helloTo);
        
        String helloStr = formatString(helloTo);
        printHello(helloStr);
    } finally {
        span.finish();
    }
}

private  String formatString(String helloTo) {
    Span span = tracer.buildSpan("formatString").start();
    try (Scope scope = tracer.scopeManager().activate(span)) {
        String helloStr = String.format("Hello, %s!", helloTo);
        span.log(ImmutableMap.of("event", "string-format", "value", helloStr));
        return helloStr;
    } finally {
        span.finish();
    }
}

private void printHello(String helloStr) {
    Span span = tracer.buildSpan("printHello").start();
    try (Scope scope = tracer.scopeManager().activate(span)) {
        System.out.println(helloStr);
        span.log(ImmutableMap.of("event", "println"));
    } finally {
        span.finish();
    }
}

代码说明:

  • trace.scopeManager().active(span) 使当前span变为active span(每个线程内只能有一个active span)。当这个span关闭后,上一个span会自动又变为active span。
  • Scope 实现了AutoCloseable接口, 所以我们可以使用try-with-resource语法.
  • 如果当前(当前线程内)已经有一个active span的话,使用buildSpan()创建新span的时候,会自动将当前active span设置为新span的父span。

修改完后运行程序,效果和前面我们自己在函数间传递span信息是一样的。

总结

本文展示了如何在线程内部传递链路信息,下篇文章介绍如何跟踪RPC请求,也就是如何在网络间(跨进程/线程)传递链路信息。

文章目录