zipkinContext.TraceID.ToHex undefined (type model.TraceID has no field or method ToHex)

[dayadev]

Having this issue today

[basvanbeek]

We'll need more information (show me the code) to triage this...

[dayadev]

We'll need more information (show me the code) to triage this...

tracer, err := zipkin.NewTracer(recorder, zipkin.ClientServerSameSpan(false))
	if err != nil {
		logger.WithFields(logrus.Fields{
			"error": err,
		}).Error("Unable to create Zipkin tracer")
	}

	opentracing.InitGlobalTracer(tracer)

spanCtx := opentracing.SpanFromContext(ctx).Context()
traceID := spanCtx.(zipkin.SpanContext).TraceID.ToHex()
spanID := spanCtx.(zipkin.SpanContext).SpanID

[basvanbeek]

Ah yes,

So the problem is you're using the old SpanContext object from the native zipkin-go-opentracing tracer. From version 0.4.0 onwards this project has become a bridge to the zipkin-go native tracer which has its own SpanContext object and logic which is a bit different from the one you used.

For pure OpenTracing API usage this makes no difference but you are actually using non portable logic that ties you to Zipkin specifically. You can do two things...

1. start to use zipkin-go native tracer which brings you the best idiomatic usage for Zipkin instrumented platforms and is fully supported by the OpenZipkin community
2. use this new zipkin-go-opentracing bridge but adjust your custom logic to be zipkin-go compatible.

If you want the best experience I'd suggest switching to native Zipkin Go. If you are determined to stick with OpenTracing (which will be superseded by OpenTelemetry so you'd have to invest heavily in the future anyway) you can do this for now:

import (
	zipkinot "github.com/openzipkin-contrib/zipkin-go-opentracing"
	zipkin "github.com/openzipkin/zipkin-go"
)

func main () {
	// ...

	nativeTracer, err := zipkin.NewTracer(reporter, ...)
	if err != nil {
		// ...
	}
	tracer := zipkinot.Wrap(nativeTracer)

	// InitGlobalTracer is deprecated...
	opentracing.SetGlobalTracer(tracer)

	ctx := opentracing.ContextWithSpan(context.Background(), span)
	spanCtx := opentracing.SpanFromContext(ctx).Context().(zipkinot.SpanContext)
	traceID := spanCtx.TraceID.String()
	spanID := spanCtx.ID.String()

	// ...
}

[jcchavezs]

@dd I see you want to extract the IDs from the span and I suspect it is because you want to correlate it somewhere (maybe logs), this can be achieved in many ways and they can even be transparent. opentracing-go does not support access to identifiers (see the full thread in opentracing/opentracing-go#188) and hence we don't either so I would suggest that you explain more your specific use case and we can suggest you more concrete solutions. In any case, I would also suggest using zipkin-go instead as you will get much more value out of it.

[dayadev]

@dd I see you want to extract the IDs from the span and I suspect it is because you want to correlate it somewhere (maybe logs), this can be achieved in many ways and they can even be transparent. opentracing-go does not support access to identifiers (see the full thread in opentracing/opentracing-go#188) and hence we don't either so I would suggest that you explain more your specific use case and we can suggest you more concrete solutions. In any case, I would also suggest using zipkin-go instead as you will get much more value out of it.

@jcchavezs Yes, it is used for logging purposes and I am trying to set it up in the main function as suggested by @basvanbeek as below

reporter := zipkinhttp.NewReporter(zipkinHTTPEndpoint)
	defer reporter.Close()

	// create our local service endpoint
	endpoint, err := zipkin.NewEndpoint(serviceName, "localhost:8080")
	if err != nil {
		logger.WithFields(logrus.Fields{
			"error": err,
		}).Error("unable to create local endpoint")
	}

	// initialize our tracer
	nativeTracer, err := zipkin.NewTracer(reporter, zipkin.WithLocalEndpoint(endpoint))
	if err != nil {
		logger.WithFields(logrus.Fields{
			"error": err,
		}).Error("Unable to create Zipkin tracer")
	}

	// use zipkin-go-opentracing to wrap our tracer
	tracer := zipkinot.Wrap(nativeTracer)

	opentracing.SetGlobalTracer(tracer)

server = grpc.NewServer(grpc.Creds(creds), grpc.UnaryInterceptor(grpc_middleware.ChainUnaryServer(
			grpc_opentracing.UnaryServerInterceptor(grpc_opentracing.WithTracer(tracer)),
			middleware.LoggingInterceptor(logger))), grpc.MaxSendMsgSize(50000000))

If i do the above for some reasons I dont know, the service calls never reach my service.

I believe this is where its hanging while returning the response

// Send implements reporter
func (r *httpReporter) Send(s model.SpanModel) {
	r.spanC <- &s
}

[dayadev]

This explains the specific usecase, I have
https://github.com/dayadev/grpc-zipkin-with-grpc-gateway

Looks like this is happening only for REST and not grpc.
For grpc which is working fine here , https://github.com/dayadev/grpc-zipkin-with-grpc-gateway/tree/grpconly
Error:

goroutine 19 [chan send]:
github.com/openzipkin/zipkin-go/reporter/http.(*httpReporter).Send(0xc000176090, 0x0, 0x3858e8cd955b60d0, 0x7483af93806da3da, 0xc000152300, 0x0, 0xc0001522fa, 0x0, 0x0, 0x15ca19e, ...)
	/Users/dd/go/src/github.com/openzipkin/zipkin-go/reporter/http/http.go:60 +0x84
github.com/openzipkin/zipkin-go.(*spanImpl).Finish(0xc0001920e0)
	/Users/dd/go/src/github.com/openzipkin/zipkin-go/span_implementation.go:83 +0x113
github.com/openzipkin-contrib/zipkin-go-opentracing.(*spanImpl).Finish(0xc000148440)
	/Users/dd/go/src/github.com/openzipkin-contrib/zipkin-go-opentracing/span.go:107 +0x45
myservicepkg/service.ts.myHandler(0xc000140540, 0x1685740, 0xc00017e160, 0x1675560, 0xc000150100, 0x1675580, 0xc000150120, 0x1675540, 0xc000150140, 0x1680c20, ...)
	/Users/dd/go/src/myservicepkg/service/myservice.go:643 +0x1270
net/http.HandlerFunc.ServeHTTP(...)
	/usr/local/Cellar/go/1.12.7/libexec/src/net/http/server.go:1995

[basvanbeek]

I think the problem you have is in the grpc-zipkin-with-grpc-gateway you use runtime.Goexit()

From Goexit:

// Goexit terminates the goroutine that calls it. No other goroutine is affected.
// Goexit runs all deferred calls before terminating the goroutine. Because Goexit
// is not a panic, any recover calls in those deferred functions will return nil.

So basically you trigger the reporter to be closed. I suggest not using Goexit. If you want a nice way of running multiple goroutines and having a way to handle graceful shutdown take a look at run.Group

See: https://github.com/oklog/run

[dayadev]

I think the problem you have is in the grpc-zipkin-with-grpc-gateway you use runtime.Goexit()

From Goexit:

// Goexit terminates the goroutine that calls it. No other goroutine is affected.
// Goexit runs all deferred calls before terminating the goroutine. Because Goexit
// is not a panic, any recover calls in those deferred functions will return nil.

So basically you trigger the reporter to be closed. I suggest not using Goexit. If you want a nice way of running multiple goroutines and having a way to handle graceful shutdown take a look at run.Group

See: https://github.com/oklog/run

Wooh. Right! Thank you so much!

[dayadev]

I know I closed this issue, but with the approach here using the grpc_opentracing.UnaryServerInterceptor(grpc_opentracing.WithTracer(tracer) interceptor, this doesn't propagate the trace to the outgoing context and I have the context below without a trace id, am I still missing something?

(*context.valueCtx)(0xc025368300)(context.Background.WithCancel.WithCancel.WithValue(peer.peerKey{}, &peer.Peer{Addr:(*net.TCPAddr)(0xc01af43b90), AuthInfo:credentials.AuthInfo(nil)}).WithValue(metadata.mdIncomingKey{}, metadata.MD{":authority":[]string{"127.0.0.1:9090"}, "content-type":[]string{"application/grpc"}, "user-agent":[]string{"grpc-go/1.24.0-dev"}}).WithValue(grpc.streamKey{}, <stream: 0xc0001ee100, /applicationmanager.v1alpha1.applicationmanager/GetApplicationByID>).WithValue(opentracing.contextKey{}, &zipkintracer.spanImpl{tracer:(*zipkintracer.tracerImpl)(0xc0000dd520), zipkinSpan:(*zipkin.spanImpl)(0xc0253c62a0), startTime:time.Time{wall:0xbf521d2f74125280, ext:16156207871, loc:(*time.Location)(0x1e01560)}, observer:otobserver.SpanObserver(nil)}))

Below is the tracer I have

(*zipkintracer.tracerImpl)(0xc000136660)({
 zipkinTracer: (*zipkin.Tracer)(0xc00014c820)({
  defaultTags: (map[string]string) {
  },
  extractFailurePolicy: (zipkin.ExtractFailurePolicy) 0,
  sampler: (zipkin.Sampler) 0x15c1240,
  generate: (*idgenerator.randomID64)(0x1ec3de0)({
  }),
  reporter: (*http.httpReporter)(0xc0001822d0)({
   url: (string) (len=48) "http://xyz:9411/api/v2/spans",
   client: (*http.Client)(0xc000134f30)({
    Transport: (http.RoundTripper) <nil>,
    CheckRedirect: (func(*http.Request, []*http.Request) error) <nil>,
    Jar: (http.CookieJar) <nil>,
    Timeout: (time.Duration) 5s
   }),
   logger: (*log.Logger)(0xc00014c640)({
    mu: (sync.Mutex) {
     state: (int32) 0,
     sema: (uint32) 0
    },
    prefix: (string) "",
    flag: (int) 3,
    out: (*os.File)(0xc000010018)({
     file: (*os.file)(0xc0000880c0)({
      pfd: (poll.FD) {
       fdmu: (poll.fdMutex) {
        state: (uint64) 0,
        rsema: (uint32) 0,
        wsema: (uint32) 0
       },
       Sysfd: (int) 2,
       pd: (poll.pollDesc) {
        runtimeCtx: (uintptr) <nil>
       },
       iovecs: (*[]syscall.Iovec)(<nil>),
       csema: (uint32) 0,
       isBlocking: (uint32) 1,
       IsStream: (bool) true,
       ZeroReadIsEOF: (bool) true,
       isFile: (bool) true
      },
      name: (string) (len=11) "/dev/stderr",
      dirinfo: (*os.dirInfo)(<nil>),
      nonblock: (bool) false,
      stdoutOrErr: (bool) true
     })
    }),
    buf: ([]uint8) <nil>
   }),
   batchInterval: (time.Duration) 1s,
   batchSize: (int) 100,
   maxBacklog: (int) 1000,
   sendMtx: (*sync.Mutex)(0xc000132420)({
    state: (int32) 0,
    sema: (uint32) 0
   }),
   batchMtx: (*sync.Mutex)(0xc000132428)({
    state: (int32) 0,
    sema: (uint32) 0
   }),
   batch: ([]*model.SpanModel) {
   },
   spanC: (chan *model.SpanModel) 0xc0001302a0,
   quit: (chan struct {}) (cap=1) 0xc000130300,
   shutdown: (chan error) (cap=1) 0xc0000b0360,
   reqCallback: (http.RequestCallbackFn) <nil>,
   serializer: (reporter.JSONSerializer) {
   }
  }),
  localEndpoint: (*model.Endpoint)(<nil>),
  noop: (int32) 0,
  sharedSpans: (bool) true,
  unsampledNoop: (bool) false
 }),
 textPropagator: (*zipkintracer.textMapPropagator)(0xc0000ae090)({
  tracer: (*zipkintracer.tracerImpl)(0xc000136660)(<already shown>)
 }),
 accessorPropagator: (*zipkintracer.accessorPropagator)(0xc0000ae098)({
  tracer: (*zipkintracer.tracerImpl)(0xc000136660)(<already shown>)
 }),
 opts: (*zipkintracer.TracerOptions)(0xc000136680)({
  observer: (otobserver.Observer) <nil>,
  b3InjectOpt: (zipkintracer.B3InjectOption) 0
 })
})

Here is the repo again, https://github.com/dayadev/grpc-zipkin-with-grpc-gateway

[dayadev]

I was able to further debug this and found when grpc_opentracing.UnaryServerInterceptor(grpc_opentracing.WithTracer(tracer) is invoked on a request, inside the open tracing interceptor, opentracing: Unknown or unsupported Inject/Extract format while extracting the parent context span from the tracer at tracer.Extract(opentracing.HTTPHeaders, metadataTextMap(md))

[basvanbeek]

@dayadev can you check if latest in master fixes your issue?

[dayadev]

@dayadev can you check if latest in master fixes your issue?

@basvanbeek Yes, this fixed the issue. Thank you!