JAVA

OpenTracing Java Library教程(2)——进程间传递SpanContext

Posted Cola🌀

目标

学习如何：

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

开发步骤

跟踪不同的函数

上篇文章的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。

产生这个结果的原因是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都是最后一个，这个结果是比较符合预期的。我们再看下链路图：

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

从这个链路图就可以看出来函数间的调用关系，以及各个调用的耗时。如果点击每个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信息是一样的。