fixup span tags and logs

Signed-off-by: Vasiliy Tolstov <v.tolstov@unistack.org>

go.mod

@@ -1,10 +1,10 @@
-module go.unistack.org/micro-tracer-opentracing/v3
+module go.unistack.org/micro-tracer-opentracing/v4
 
 go 1.20
 
 require (
 	github.com/opentracing/opentracing-go v1.2.0
-	go.unistack.org/micro/v3 v3.10.25
+	go.unistack.org/micro/v4 v4.0.13
 )
 
-require github.com/stretchr/testify v1.8.1 // indirect
+require github.com/stretchr/testify v1.8.3 // indirect

go.sum

@@ -1,21 +1,13 @@
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
-github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/opentracing/opentracing-go v1.2.0 h1:uEJPy/1a5RIPAJ0Ov+OIO8OxWu77jEv+1B0VhjKrZUs=
 github.com/opentracing/opentracing-go v1.2.0/go.mod h1:GxEUsuufX4nBwe+T+Wl9TAgYrxe9dPLANfrWvHYVTgc=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
-github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
-github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
-github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
-github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
-github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
-go.unistack.org/micro/v3 v3.10.25 h1:A0epdZHOqjnXx103wwFhPKgmvVVbScvfbmn3HmHz1wE=
-go.unistack.org/micro/v3 v3.10.25/go.mod h1:ALkeXpqChYDjx8KPi7tz9mmIyOnob6nlNswsg8BnZjQ=
-gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
-gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
+github.com/stretchr/testify v1.8.3 h1:RP3t2pwF7cMEbC1dqtB6poj3niw/9gnV4Cjg5oW5gtY=
+github.com/stretchr/testify v1.8.3/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo=
+go.unistack.org/micro/v4 v4.0.13 h1:wyprk+KNAv/zR6bri6p6ucmXcJ9WyZ/vzru4zjPd8dA=
+go.unistack.org/micro/v4 v4.0.13/go.mod h1:ZDgU9931vm2l7X6RN/6UuwRIVp24GRdmQ7dKmegArk4=
 gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
-gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

opentracing.go

@@ -7,8 +7,10 @@ import (
 
 	ot "github.com/opentracing/opentracing-go"
 	otlog "github.com/opentracing/opentracing-go/log"
-	"go.unistack.org/micro/v3/metadata"
-	"go.unistack.org/micro/v3/tracer"
+	"go.unistack.org/micro/v4/metadata"
+	"go.unistack.org/micro/v4/options"
+	"go.unistack.org/micro/v4/tracer"
+	rutil "go.unistack.org/micro/v4/util/reflect"
 )
 
 var _ tracer.Tracer = &otTracer{}
@@ -26,9 +28,11 @@ func (t *otTracer) Flush(ctx context.Context) error {
 	return nil
 }
 
-func (t *otTracer) Init(opts ...tracer.Option) error {
+func (t *otTracer) Init(opts ...options.Option) error {
 	for _, o := range opts {
-		o(&t.opts)
+		if err := o(&t.opts); err != nil {
+			return err
+		}
 	}
 
 	if tr, ok := t.opts.Context.Value(tracerKey{}).(ot.Tracer); ok {
@@ -40,7 +44,12 @@ func (t *otTracer) Init(opts ...tracer.Option) error {
 	return nil
 }
 
-func (t *otTracer) Start(ctx context.Context, name string, opts ...tracer.SpanOption) (context.Context, tracer.Span) {
+type spanContext interface {
+	TraceID() idStringer
+	SpanID() idStringer
+}
+
+func (t *otTracer) Start(ctx context.Context, name string, opts ...options.Option) (context.Context, tracer.Span) {
 	options := tracer.NewSpanOptions(opts...)
 	var span ot.Span
 	switch options.Kind {
@@ -53,17 +62,50 @@ func (t *otTracer) Start(ctx context.Context, name string, opts ...tracer.SpanOp
 	case tracer.SpanKindServer, tracer.SpanKindConsumer:
 		ctx, span = t.startSpanFromIncomingContext(ctx, name)
 	}
+
 	sp := &otSpan{span: span, opts: options}
+
+	spctx := span.Context()
+	if v, ok := spctx.(spanContext); ok {
+		sp.traceID = v.TraceID().String()
+		sp.spanID = v.SpanID().String()
+	} else {
+		if val, err := rutil.StructFieldByName(spctx, "TraceID"); err == nil {
+			sp.traceID = fmt.Sprintf("%v", val)
+		}
+		if val, err := rutil.StructFieldByName(spctx, "SpanID"); err == nil {
+			sp.spanID = fmt.Sprintf("%v", val)
+		}
+	}
+
 	return tracer.NewSpanContext(ctx, sp), sp
 }
 
+type idStringer struct {
+	s string
+}
+
+func (s idStringer) String() string {
+	return s.s
+}
+
 type otSpan struct {
 	span      ot.Span
+	spanID    string
+	traceID   string
 	opts      tracer.SpanOptions
 	status    tracer.SpanStatus
 	statusMsg string
 }
 
+func (os *otSpan) TraceID() string {
+	return os.traceID
+}
+
+func (os *otSpan) SpanID() string {
+	return os.spanID
+}
+
 func (os *otSpan) SetStatus(st tracer.SpanStatus, msg string) {
 	os.status = st
 	os.statusMsg = msg
@@ -77,33 +119,49 @@ func (os *otSpan) Tracer() tracer.Tracer {
 	return &otTracer{tracer: os.span.Tracer()}
 }
 
-func (os *otSpan) Finish(opts ...tracer.SpanOption) {
+func (os *otSpan) AddLogs(kv ...interface{}) {
+	os.span.LogKV(kv...)
+}
+
+func (os *otSpan) Finish(opts ...options.Option) {
 	if len(os.opts.Labels)%2 != 0 {
 		os.opts.Labels = os.opts.Labels[:len(os.opts.Labels)-1]
 	}
+	os.opts.Labels = tracer.UniqLabels(os.opts.Labels)
 	for idx := 0; idx < len(os.opts.Labels); idx += 2 {
-		switch os.opts.Labels[idx] {
+		k, ok := os.opts.Labels[idx].(string)
+		if !ok {
+			continue
+		}
+		v, ok := os.opts.Labels[idx+1].(string)
+		if !ok {
+			v = fmt.Sprintf("%v", os.opts.Labels[idx+1])
+		}
+		switch k {
 		case "err":
 			os.status = tracer.SpanStatusError
-			os.statusMsg = fmt.Sprintf("%v", os.opts.Labels[idx+1])
+			os.statusMsg = v
 		case "error":
 			continue
 		case "X-Request-Id", "x-request-id":
-			os.span.SetTag("x-request-id", os.opts.Labels[idx+1])
-		case "rpc.call", "rpc.call_type", "rpc.flavor", "span.kind", "sdk.database", "db.statement", "db.args", "args", "db.query", "query", "method":
-			os.span.SetTag(fmt.Sprintf("%v", os.opts.Labels[idx]), fmt.Sprintf("%v", os.opts.Labels[idx+1]))
+			os.span.SetTag("x-request-id", v)
+		case "rpc.call", "rpc.call_type", "rpc.flavor", "rpc.service", "rpc.method",
+			"sdk.database", "db.statement", "db.args", "db.query", "db.method",
+			"messaging.destination.name", "messaging.source.name", "messaging.operation":
+			os.span.SetTag(k, v)
 		default:
-			os.span.LogKV(os.opts.Labels[idx], os.opts.Labels[idx+1])
+			os.span.LogKV(k, v)
 		}
 	}
 	if os.status == tracer.SpanStatusError {
 		os.span.SetTag("error", true)
 		os.span.LogKV("error", os.statusMsg)
 	}
+	os.span.SetTag("span.kind", os.opts.Kind)
 	os.span.Finish()
 }
 
-func (os *otSpan) AddEvent(name string, opts ...tracer.EventOption) {
+func (os *otSpan) AddEvent(name string, opts ...options.Option) {
 	os.span.LogFields(otlog.Event(name))
 }
 
@@ -127,15 +185,11 @@ func (os *otSpan) AddLabels(labels ...interface{}) {
 	os.opts.Labels = append(os.opts.Labels, labels...)
 }
 
-func NewTracer(opts ...tracer.Option) *otTracer {
+func NewTracer(opts ...options.Option) *otTracer {
 	options := tracer.NewOptions(opts...)
 	return &otTracer{opts: options}
 }
 
-func spanFromContext(ctx context.Context) ot.Span {
-	return ot.SpanFromContext(ctx)
-}
-
 func (t *otTracer) startSpanFromAny(ctx context.Context, name string, opts ...ot.StartSpanOption) (context.Context, ot.Span) {
 	if tracerSpan, ok := tracer.SpanFromContext(ctx); ok && tracerSpan != nil {
 		return t.startSpanFromContext(ctx, name, opts...)

opentracing_test.go

@@ -2,49 +2,31 @@ package opentracing
 
 import (
 	"context"
-	"sync"
 	"testing"
 
-	"github.com/opentracing/opentracing-go"
-	"go.unistack.org/micro/v3/metadata"
+	"github.com/opentracing/opentracing-go/mocktracer"
+	"go.unistack.org/micro/v4/metadata"
+	"go.unistack.org/micro/v4/tracer"
 )
 
-func TestStartSpanFromIncomingContext(t *testing.T) {
-	md := metadata.New(2)
-	md.Set("key", "val")
-
-	var g sync.WaitGroup
-
+func TestTraceID(t *testing.T) {
+	md := metadata.New(1)
 	ctx, cancel := context.WithCancel(context.Background())
 	defer cancel()
 	ctx = metadata.NewIncomingContext(ctx, md)
 
-	tracer := opentracing.GlobalTracer()
-
-	g.Add(8000)
-	cherr := make(chan error)
-	for i := 0; i < 8000; i++ {
-		go func() {
-			defer g.Done()
-			_, sp, err := startSpanFromIncomingContext(ctx, tracer, "test")
-			if err != nil {
-				cherr <- err
-			}
-			sp.Finish()
-		}()
-	}
-
-	for {
-		select {
-		default:
-			g.Wait()
-			close(cherr)
-		case err, ok := <-cherr:
-			if err != nil {
+	tr := NewTracer(Tracer(mocktracer.New()))
+	if err := tr.Init(); err != nil {
 		t.Fatal(err)
-			} else if !ok {
-				return
-			}
-		}
+	}
+
+	var sp tracer.Span
+
+	ctx, sp = tr.Start(ctx, "test")
+	if v := sp.TraceID(); v != "43" {
+		t.Fatalf("invalid span trace id %#+v", v)
+	}
+	if v := sp.SpanID(); v != "44" {
+		t.Fatalf("invalid span span id %#+v", v)
 	}
 }

options.go

@@ -2,11 +2,11 @@ package opentracing
 
 import (
 	"github.com/opentracing/opentracing-go"
-	"go.unistack.org/micro/v3/tracer"
+	"go.unistack.org/micro/v4/options"
 )
 
 type tracerKey struct{}
 
-func Tracer(ot opentracing.Tracer) tracer.Option {
-	return tracer.SetOption(tracerKey{}, ot)
+func Tracer(ot opentracing.Tracer) options.Option {
+	return options.ContextOption(tracerKey{}, ot)
 }