Opentracing实战
解决微服务架构下，链路追踪，问题定位和可视化分析等问题，链路追踪还是微服务可观测性的重要基石，本文就实战了在Go项目中如何将opentracing落地
背景
在没有链路追踪系统的情况下，如果只要少数几个服务，或许还可以通过日志来排查定位问题。但是如果服务一旦超过10个，那么再想通过日志来定位分析问题将无比繁琐。 因为，你先要从大量的日志中删筛选出某次请求的日志数据，才能进行后续的定位分析。 倘若日志系统也不够完善，日志对于调试毫无帮助，那又得退回到最原始的方式，通过代码断点和增加日志，等待问题复现，或者通过肉眼检查代码。 不是说这种方式不行，而是大部分的程序员的业务需求比较紧张，这样的排查手段效率和收益远远达不到要求（如果你有时间，当我没说 🐶）。
在实际场景中，我也遇到了这样的问题：
- 日志系统里包含了过少的信息，对于调试几乎没有帮助 (几乎只有错误日志，缺少输出上下文的日志)。
- 服务调用复杂，一个请求失败，只能透过错误码和错误信息进行判断是否存在调用失败的情况。
- 调用链路复杂的情况下，想要对某个请求进行优化，无从下手。
这里只列举了跟trace相关的一些原始场景，当然从上面的描述中还能发现日志系统不够完善，对调试不友好，不过这里首要解决的问题是链路追踪问题。
如果对路链路追踪没有概念，还望自行查阅资料，这里不会过多介绍～
Opentracing
注意：Opentracing 是一套标准接口，而不是具体实现。
这里就实战opentracing + jaeger 的链路追踪方案。其中 opentracing 是一套标准接口，而jaeger是包含了 opentracing 的实现的一套工具。 Trace链路简单示例如下：
Trace
描述在分布式系统中的一次"事务"。
Span
表示工作流的一部分的命名和定时操作。可以接受标签(Tag Key:Value)，以及附加到特定span实例的标注(Annotation)，如时间戳和结构化日志。
SpanContext
追踪伴随分布式事务的信息，包括它通过网络或通过消息总线将服务传递给服务的时间。span上下文包含TraceId、SpanId和追踪系统需要传播到下游服务的其他数据。
实战
这里我准备的是 Go 项目，服务之间通过gRPC通信。链路如下：
+-- process internal trace2
|
+---> process internal trace1
|
| +---> server-b trace(gRPC)
entry(HTTP) ---> server-a trace--gRPC--|
+---> server-c trace(gRPC)
|
+----> process internal trace3
从上图中可以明确，我们的目标是：实践跨服务调用和服务内部调用的链路追踪，配合jaeger我们还可以将链路信息可视化。
我有了服务，怎么实施落地？
为了回答这个问题，我把这个问题结合opentracing的概念再分解一下：
- ParentSpan 从哪儿来？
- ChildSpan由ParentSpan创建，那么什么时候创建？
- 链路Tracer从哪儿来？
- Trace信息怎么传递？
- 链路信息如何搜集？
Parent-Span 从哪儿来？链路从哪里开始。
在上述的实践目标中，我们只有一个入口服务，那么很明显每一次的"事务"都是在这个入口（http entry）开启的。我写了如下的中间件（基于gin）。
// 这个定义是因为opentracing没有定义获取traceId 和spanId的方法，而我又实践了 zipkin 和 jaeger
type getTraceID func(spCtx opentracing.SpanContext) string
// get trace info from header, if not then create an new one
func Opentracing(getTraceIdFromSpanContext getTraceID) gin.HandlerFunc {
return func(c *gin.Context) {
// prepare work ...
// 这里首先尝试从客户端请求中获取到trace链路信息，如果获取到则创建child span.
carrier := opentracing.HTTPHeadersCarrier(c.Request.Header)
clientSpCtx, err := tracer.Extract(opentracing.HTTPHeaders, carrier)
if err != nil {
log.Printf("could not extract trace data from http header, err=%v\n", err)
}
// derive a span or create an root span
sp = tracer.StartSpan(
c.Request.RequestURI,
opentracing.ChildOf(clientSpCtx),
)
defer sp.Finish()
// do some work
// ...
// 将含有span的 context.Context 设置到 gin.Context 用于传递span
ctx = opentracing.ContextWithSpan(c.Request.Context(), sp)
c.Set(_traceContextKey, ctx)
traceId := getTraceIdFromSpanContext(sp.Context())
c.Header("X-Trace-Id", traceId)
// continue process request
c.Next()
// do some work
// ...
}
}
Child-Span什么时候创建？
其实在上述的中间件里已经有了体现（跨服务调用时）。这里主要有两种场景：跨服务调用，服务内部调，这两种的区别在于是否是同一个进程。
针对跨服务调用，我们使用了gRPC来通信，那么创建的时机就在于gRPC客户端发起调用时，需要创建一个childSpan并传递给服务端，服务端需要解析到该span并在当次请求中使用。
而对于服务内部的调用，相较而言会更简单一点，直接使用该span创建childSpan就好了。
这里需要注意的是，一般来说在Go开发过程中推荐使用Context作为函数调用的第一个参数，opentracing也考虑了这一点，如下： 官方提供了对应的方法，来帮助使用者把span和context.Context一起使用。
// ContextWithSpan returns a new `context.Context` that holds a reference to
// the span. If span is nil, a new context without an active span is returned.
func ContextWithSpan(ctx context.Context, span Span) context.Context {
if span != nil {
if tracerWithHook, ok := span.Tracer().(TracerContextWithSpanExtension); ok {
ctx = tracerWithHook.ContextWithSpanHook(ctx, span)
}
}
return context.WithValue(ctx, activeSpanKey, span)
}
// SpanFromContext returns the `Span` previously associated with `ctx`, or
// `nil` if no such `Span` could be found.
//
// NOTE: context.Context != SpanContext: the former is Go's intra-process
// context propagation mechanism, and the latter houses OpenTracing's per-Span
// identity and baggage information.
func SpanFromContext(ctx context.Context) Span {
val := ctx.Value(activeSpanKey)
if sp, ok := val.(Span); ok {
return sp
}
return nil
}
在中间件那里，我们已经把 context.Context 设置到了 gin.Context 中去了，因此在后续的使用中，我们需要把它从 gin.Context 取出并传递。
// traceHdl is a trace handler from HTTP request
func traceHdl(c *gin.Context) {
// get root Context from request
// TODO: try to use c.Request.WithContext() to set context
ctx, ok := c.Get(x.GetTraceContextKey())
if !ok {
panic("impossible")
}
// ctx在服务内部传递，ctx含有span信息
if err := clientCall(ctx.(context.Context)); err != nil {
c.JSON(http.StatusInternalServerError, gin.H{"message": err.Error()})
return
}
// response to client
c.JSON(http.StatusOK, gin.H{"message": "traceHdl done"})
}
func clientCall(ctx context.Context) error {
// 注意：这里使用了gRPC来做跨服务的调用，对于ctx的处理，是通过interceptor实现的。
// 这部分代码会在后面贴上，但是逻辑也跟类似，只是多了需要适配gRPC数据传递的规则。
_, err := serverAConn.PingA(ctx, &pb.PingAReq{
Now: time.Now().Unix(),
From: "client",
})
if err != nil {
return err
}
// 这里演示进程内链路
return processInternalTrace1(ctx)
}
// internal process trace example 1
func processInternalTrace1(ctx context.Context) error {
ctx2, sp := x.StartSpanFromContext(ctx)
defer sp.Finish()
println("processInternalTrace1 called")
// do some ops
time.Sleep(10 * time.Millisecond)
return processInternalTrace2(ctx2)
}
gRPC interceptor 实现如下：服务端工作内容相似，只是从inject操作变成了extract。
// client interceptor
func OpenTracingClientInterceptor(tracer opentracing.Tracer, optFuncs ...Option) grpc.UnaryClientInterceptor {
otgrpcOpts := newOptions()
otgrpcOpts.apply(optFuncs...)
return func(
ctx context.Context,m
ethod string,
req, resp interface{},
cc *grpc.ClientConn,
invoker grpc.UnaryInvoker,
opts ...grpc.CallOption,
) error {
var err error
var parentCtx opentracing.SpanContext
if parent := opentracing.SpanFromContext(ctx); parent != nil {
parentCtx = parent.Context()
}
// ...
clientSpan := tracer.StartSpan(
method,
opentracing.ChildOf(parentCtx),
ext.SpanKindRPCClient,
gRPCComponentTag,
)
defer clientSpan.Finish()
// 注入
ctx = injectSpanContext(ctx, tracer, clientSpan)
// ...
// 调用
err = invoker(ctx, method, req, resp, cc, opts...)
// ...
return err
}
}
func injectSpanContext(ctx context.Context, tracer opentracing.Tracer, clientSpan opentracing.Span) context.Context {
md, ok := metadata.FromOutgoingContext(ctx)
if !ok {
md = metadata.New(nil)
} else {
md = md.Copy()
}
mdWriter := metadataReaderWriter{md}
err := tracer.Inject(clientSpan.Context(), opentracing.HTTPHeaders, mdWriter)
// We have no better place to record an error than the Span itself :-/
if err != nil {
clientSpan.LogFields(log.String("event", "Tracer.Inject() failed"), log.Error(err))
}
return metadata.NewOutgoingContext(ctx, md)
}
至此我们就介绍完了，服务间（gRPC）调用和服务内（context）调用的childSpan的创建和传递。
链路Tracer从哪儿来？
先说Tracer有什么用，Tracer是用来管理Span的统筹者，负责创建span和传播span。
// Tracer负责创建span和传播span
type Tracer interface {
// Create, start, and return a new Span with the given `operationName` and
// incorporate the given StartSpanOption `opts`. (Note that `opts` borrows
// from the "functional options" pattern, per
// http://dave.cheney.net/2014/10/17/functional-options-for-friendly-apis)
//
// A Span with no SpanReference options (e.g., opentracing.ChildOf() or
// opentracing.FollowsFrom()) becomes the root of its own trace.
//
// Examples:
//
// var tracer opentracing.Tracer = ...
//
// // The root-span case:
// sp := tracer.StartSpan("GetFeed")
//
// // The vanilla child span case:
// sp := tracer.StartSpan(
// "GetFeed",
// opentracing.ChildOf(parentSpan.Context()))
//
// // All the bells and whistles:
// sp := tracer.StartSpan(
// "GetFeed",
// opentracing.ChildOf(parentSpan.Context()),
// opentracing.Tag{"user_agent", loggedReq.UserAgent},
// opentracing.StartTime(loggedReq.Timestamp),
// )
//
StartSpan(operationName string, opts ...StartSpanOption) Span
// Inject() takes the `sm` SpanContext instance and injects it for
// propagation within `carrier`. The actual type of `carrier` depends on
// the value of `format`.
//
// OpenTracing defines a common set of `format` values (see BuiltinFormat),
// and each has an expected carrier type.
//
// Other packages may declare their own `format` values, much like the keys
// used by `context.Context` (see https://godoc.org/context#WithValue).
//
// Example usage (sans error handling):
//
// carrier := opentracing.HTTPHeadersCarrier(httpReq.Header)
// err := tracer.Inject(
// span.Context(),
// opentracing.HTTPHeaders,
// carrier)
//
// NOTE: All opentracing.Tracer implementations MUST support all
// BuiltinFormats.
//
// Implementations may return opentracing.ErrUnsupportedFormat if `format`
// is not supported by (or not known by) the implementation.
//
// Implementations may return opentracing.ErrInvalidCarrier or any other
// implementation-specific error if the format is supported but injection
// fails anyway.
//
// See Tracer.Extract().
Inject(sm SpanContext, format interface{}, carrier interface{}) error
// Extract() returns a SpanContext instance given `format` and `carrier`.
//
// OpenTracing defines a common set of `format` values (see BuiltinFormat),
// and each has an expected carrier type.
//
// Other packages may declare their own `format` values, much like the keys
// used by `context.Context` (see
// https://godoc.org/golang.org/x/net/context#WithValue).
//
// Example usage (with StartSpan):
//
//
// carrier := opentracing.HTTPHeadersCarrier(httpReq.Header)
// clientContext, err := tracer.Extract(opentracing.HTTPHeaders, carrier)
//
// // ... assuming the ultimate goal here is to resume the trace with a
// // server-side Span:
// var serverSpan opentracing.Span
// if err == nil {
// span = tracer.StartSpan(
// rpcMethodName, ext.RPCServerOption(clientContext))
// } else {
// span = tracer.StartSpan(rpcMethodName)
// }
//
//
// NOTE: All opentracing.Tracer implementations MUST support all
// BuiltinFormats.
//
// Return values:
// - A successful Extract returns a SpanContext instance and a nil error
// - If there was simply no SpanContext to extract in `carrier`, Extract()
// returns (nil, opentracing.ErrSpanContextNotFound)
// - If `format` is unsupported or unrecognized, Extract() returns (nil,
// opentracing.ErrUnsupportedFormat)
// - If there are more fundamental problems with the `carrier` object,
// Extract() may return opentracing.ErrInvalidCarrier,
// opentracing.ErrSpanContextCorrupted, or implementation-specific
// errors.
//
// See Tracer.Inject().
Extract(format interface{}, carrier interface{}) (SpanContext, error)
}
之前已经提到了了opentracing是一套接口，那么具体的实现是在其他的工具中完成的，如jaeger。创建的时候就需要jaeger的支持了，如下：
// 使用jaeger来创建一个tracer，并注入到opentracing全局中去
func BootTracerWrapper(localServiceName string, hostPort string) error {
tracer, err := xjaeger.BootJaegerTracer(localServiceName, hostPort)
if err != nil {
return errors.Wrap(err, "BootTracerWrapper.BootZipkinTracer")
}
// 注入到全局后，就可以通过 opentracing.GlobalTracer() 来使用 tracer了
opentracing.SetGlobalTracer(tracer)
return nil
}
func BootJaegerTracer(localServiceName, hostPort string) (opentracing.Tracer, error) {
cfg := &config.Configuration{
Sampler: &config.SamplerConfig{
Type: jaeger.SamplerTypeConst,
Param: 1,
},
ServiceName: localServiceName, // 服务名
Reporter: &config.ReporterConfig{
LogSpans: true,
CollectorEndpoint: _jaegerRecorderEndpoint,
}, // 链路搜集配置
}
tracer, _, err := cfg.NewTracer(
config.Logger(jaegerlog.StdLogger),
config.ZipkinSharedRPCSpan(true),
)
if err != nil {
return nil, errors.Wrap(err, "BootJaegerTracer")
}
return tracer, nil
}
Trace信息怎么传递？
在 Child-Span什么时候创建？ 中提到了 Inject, Extract 方法，这两个方法就是用来辅助Trace信息传递的方法，
具体的实现也是在jaeger中实现的，有兴趣的可以自行查阅代码。
链路信息如何搜集？
在 #链路Tracer从哪儿来 已经提到了jaeger在创建tracer时可以指定搜集器的配置，
因此上报动作会在jaeger中完成，但是要注意的是，显式调用 sp.Finish() 才会触发上报动作。
总结
最终实战结果截图如下： 图中包含了调用链路层级关系，每个环节的耗时情况，请求的入参和结果数据（异常信息，如有）等。同时还支持自定义（Tag 和 Annotation 功能）， 如果还想要更多的信息，那么推荐使用这两个功能组合来满足需求。
再多的案例和文档，都没有自己上手实践的效果好，建议实际运行并查阅opentracing源码。所有的代码均可在 https://github.com/yeqown/opentracing-practice 中找到。
水平有限，如有错误，欢迎勘误指正🙏。