Skip to content

Commit

Permalink
refactor(tracing.opentracing): standardize
Browse files Browse the repository at this point in the history
- support lb.Retry errors
- add more logging fields as it done in opencensus
- log business error anyway
- improve codebase
- fix typo
- add more test cases
  • Loading branch information
alebabai committed Apr 19, 2021
1 parent 93f53b2 commit 5cab590
Show file tree
Hide file tree
Showing 2 changed files with 146 additions and 42 deletions.
69 changes: 46 additions & 23 deletions tracing/opentracing/endpoint.go
Expand Up @@ -2,11 +2,14 @@ package opentracing

import (
"context"
"strconv"

"github.com/opentracing/opentracing-go"
"github.com/opentracing/opentracing-go/ext"
otext "github.com/opentracing/opentracing-go/ext"
otlog "github.com/opentracing/opentracing-go/log"

"github.com/go-kit/kit/endpoint"
"github.com/go-kit/kit/sd/lb"
)

// TraceEndpoint returns a Middleware that wraps the `next` Endpoint in an
Expand All @@ -24,7 +27,7 @@ func TraceEndpoint(tracer opentracing.Tracer, operationName string, opts ...Endp
}

return func(next endpoint.Endpoint) endpoint.Endpoint {
return func(ctx context.Context, request interface{}) (interface{}, error) {
return func(ctx context.Context, request interface{}) (response interface{}, err error) {
if cfg.GetOperationName != nil {
if newOperationName := cfg.GetOperationName(ctx, operationName); newOperationName != "" {
operationName = newOperationName
Expand All @@ -50,12 +53,46 @@ func TraceEndpoint(tracer opentracing.Tracer, operationName string, opts ...Endp

ctx = opentracing.ContextWithSpan(ctx, span)

response, err := next(ctx, request)
if err := identifyError(response, err, cfg.IgnoreBusinessError); err != nil {
ext.LogError(span, err)
}
defer func() {
if err != nil {
if lbErr, ok := err.(lb.RetryError); ok {
// handle errors originating from lb.Retry
fields := make([]otlog.Field, 0, len(lbErr.RawErrors))
for idx, rawErr := range lbErr.RawErrors {
fields = append(fields, otlog.String(
"gokit.retry.error."+strconv.Itoa(idx+1), rawErr.Error(),
))
}

otext.LogError(span, lbErr, fields...)

return
}

// generic error
otext.LogError(span, err)

return
}

// test for business error
if res, ok := response.(endpoint.Failer); ok && res.Failed() != nil {
span.LogFields(
otlog.String("gokit.business.error", res.Failed().Error()),
)

if cfg.IgnoreBusinessError {
return
}

// treating business error as real error in span.
otext.LogError(span, res.Failed())

return response, err
return
}
}()

return next(ctx, request)
}
}
}
Expand All @@ -64,7 +101,7 @@ func TraceEndpoint(tracer opentracing.Tracer, operationName string, opts ...Endp
// OpenTracing Span called `operationName` with server span.kind tag..
func TraceServer(tracer opentracing.Tracer, operationName string, opts ...EndpointOption) endpoint.Middleware {
opts = append(opts, WithTags(map[string]interface{}{
ext.SpanKindRPCServer.Key: ext.SpanKindRPCServer.Value,
otext.SpanKindRPCServer.Key: otext.SpanKindRPCServer.Value,
}))

return TraceEndpoint(tracer, operationName, opts...)
Expand All @@ -74,7 +111,7 @@ func TraceServer(tracer opentracing.Tracer, operationName string, opts ...Endpoi
// OpenTracing Span called `operationName` with client span.kind tag.
func TraceClient(tracer opentracing.Tracer, operationName string, opts ...EndpointOption) endpoint.Middleware {
opts = append(opts, WithTags(map[string]interface{}{
ext.SpanKindRPCServer.Key: ext.SpanKindRPCClient.Value,
otext.SpanKindRPCClient.Key: otext.SpanKindRPCClient.Value,
}))

return TraceEndpoint(tracer, operationName, opts...)
Expand All @@ -85,17 +122,3 @@ func applyTags(span opentracing.Span, tags opentracing.Tags) {
span.SetTag(key, value)
}
}

func identifyError(response interface{}, err error, ignoreBusinessError bool) error {
if err != nil {
return err
}

if !ignoreBusinessError {
if res, ok := response.(endpoint.Failer); ok {
return res.Failed()
}
}

return nil
}
119 changes: 100 additions & 19 deletions tracing/opentracing/endpoint_test.go
Expand Up @@ -4,10 +4,15 @@ import (
"context"
"errors"
"fmt"
"github.com/go-kit/kit/sd"
"github.com/go-kit/kit/sd/lb"
otlog "github.com/opentracing/opentracing-go/log"
"reflect"
"testing"
"time"

"github.com/opentracing/opentracing-go"
"github.com/opentracing/opentracing-go/ext"
otext "github.com/opentracing/opentracing-go/ext"
"github.com/opentracing/opentracing-go/mocktracer"

"github.com/go-kit/kit/endpoint"
Expand All @@ -22,6 +27,7 @@ const (
span5 = "SPAN-5"
span6 = "SPAN-6"
span7 = "SPAN-7"
span8 = "SPAN-8"
)

var (
Expand Down Expand Up @@ -115,10 +121,31 @@ func TestTraceEndpointWithOptions(t *testing.T) {
})
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 3 with disabled IgnoreBusinessError option
// span 3 with lb error
mw = kitot.TraceEndpoint(
tracer,
span3,
kitot.WithOptions(kitot.EndpointOptions{}),
)
tracedEndpoint = mw(
lb.Retry(
5,
1*time.Second,
lb.NewRoundRobin(
sd.FixedEndpointer{
func(context.Context, interface{}) (interface{}, error) {
return nil, err1
},
},
),
),
)
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 4 with disabled IgnoreBusinessError option
mw = kitot.TraceEndpoint(
tracer,
span4,
kitot.WithIgnoreBusinessError(false),
)
tracedEndpoint = mw(func(context.Context, interface{}) (interface{}, error) {
Expand All @@ -128,30 +155,30 @@ func TestTraceEndpointWithOptions(t *testing.T) {
})
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 4 with enabled IgnoreBusinessError option
mw = kitot.TraceEndpoint(tracer, span4, kitot.WithIgnoreBusinessError(true))
// span 5 with enabled IgnoreBusinessError option
mw = kitot.TraceEndpoint(tracer, span5, kitot.WithIgnoreBusinessError(true))
tracedEndpoint = mw(func(context.Context, interface{}) (interface{}, error) {
return failedResponse{
err: err3,
}, nil
})
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 5 with OperationNameFunc option
// span 6 with OperationNameFunc option
mw = kitot.TraceEndpoint(
tracer,
span5,
span6,
kitot.WithOperationNameFunc(func(ctx context.Context, name string) string {
return fmt.Sprintf("%s-%s", "new", name)
}),
)
tracedEndpoint = mw(endpoint.Nop)
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 6 with Tags options
// span 7 with Tags options
mw = kitot.TraceEndpoint(
tracer,
span6,
span7,
kitot.WithTags(map[string]interface{}{
"tag1": "tag1",
"tag2": "tag2",
Expand All @@ -163,10 +190,10 @@ func TestTraceEndpointWithOptions(t *testing.T) {
tracedEndpoint = mw(endpoint.Nop)
_, _ = tracedEndpoint(context.Background(), struct{}{})

// span 7 with TagsFunc options
// span 8 with TagsFunc options
mw = kitot.TraceEndpoint(
tracer,
span7,
span8,
kitot.WithTags(map[string]interface{}{
"tag1": "tag1",
"tag2": "tag2",
Expand All @@ -184,7 +211,7 @@ func TestTraceEndpointWithOptions(t *testing.T) {
_, _ = tracedEndpoint(context.Background(), struct{}{})

finishedSpans := tracer.FinishedSpans()
if want, have := 7, len(finishedSpans); want != have {
if want, have := 8, len(finishedSpans); want != have {
t.Fatalf("Want %v span(s), found %v", want, have)
}

Expand Down Expand Up @@ -217,28 +244,82 @@ func TestTraceEndpointWithOptions(t *testing.T) {
t.Fatalf("Want %v, have %v", want, have)
}

if want, have := 1, len(span.Logs()); want != have {
t.Fatalf("incorrect logs count, wanted %d, got %d", want, have)
}

if want, have := []otlog.Field{
otlog.String("event", "error"),
otlog.String("error.object", "some error (previously: some error; some error; some error; some error)"),
otlog.String("gokit.retry.error.1", "some error"),
otlog.String("gokit.retry.error.2", "some error"),
otlog.String("gokit.retry.error.3", "some error"),
otlog.String("gokit.retry.error.4", "some error"),
otlog.String("gokit.retry.error.5", "some error"),
}, span.Logs()[0].Fields; reflect.DeepEqual(want, have) {
t.Fatalf("Want %q, have %q", want, have)
}

// test span 4
span = finishedSpans[3]

if want, have := span4, span.OperationName; want != have {
t.Fatalf("Want %q, have %q", want, have)
}

if want, have := (interface{})(nil), span.Tag("error"); want != have {
if want, have := true, span.Tag("error"); want != have {
t.Fatalf("Want %v, have %v", want, have)
}

if want, have := 2, len(span.Logs()); want != have {
t.Fatalf("incorrect logs count, wanted %d, got %d", want, have)
}

if want, have := []otlog.Field{
otlog.String("gokit.business.error", "some business error"),
}, span.Logs()[0].Fields; reflect.DeepEqual(want, have) {
t.Fatalf("Want %q, have %q", want, have)
}

if want, have := []otlog.Field{
otlog.String("event", "error"),
otlog.String("error.object", "some business error"),
}, span.Logs()[1].Fields; reflect.DeepEqual(want, have) {
t.Fatalf("Want %q, have %q", want, have)
}

// test span 5
span = finishedSpans[4]

if want, have := fmt.Sprintf("%s-%s", "new", span5), span.OperationName; want != have {
if want, have := span5, span.OperationName; want != have {
t.Fatalf("Want %q, have %q", want, have)
}

if want, have := (interface{})(nil), span.Tag("error"); want != have {
t.Fatalf("Want %q, have %q", want, have)
}

if want, have := 1, len(span.Logs()); want != have {
t.Fatalf("incorrect logs count, wanted %d, got %d", want, have)
}

if want, have := []otlog.Field{
otlog.String("gokit.business.error", "some business error"),
}, span.Logs()[0].Fields; reflect.DeepEqual(want, have) {
t.Fatalf("Want %q, have %q", want, have)
}

// test span 6
span = finishedSpans[5]

if want, have := span6, span.OperationName; want != have {
if want, have := fmt.Sprintf("%s-%s", "new", span6), span.OperationName; want != have {
t.Fatalf("Want %q, have %q", want, have)
}

// test span 7
span = finishedSpans[6]

if want, have := span7, span.OperationName; want != have {
t.Fatalf("Want %q, have %q", want, have)
}

Expand All @@ -250,10 +331,10 @@ func TestTraceEndpointWithOptions(t *testing.T) {
t.Fatalf("Want %q, have %q", want, have)
}

// test span 7
span = finishedSpans[6]
// test span 8
span = finishedSpans[7]

if want, have := span7, span.OperationName; want != have {
if want, have := span8, span.OperationName; want != have {
t.Fatalf("Want %q, have %q", want, have)
}

Expand Down Expand Up @@ -289,7 +370,7 @@ func TestTraceServer(t *testing.T) {
}

if want, have := map[string]interface{}{
ext.SpanKindRPCServer.Key: ext.SpanKindRPCServer.Value,
otext.SpanKindRPCServer.Key: otext.SpanKindRPCServer.Value,
}, span.Tags(); fmt.Sprint(want) != fmt.Sprint(have) {
t.Fatalf("Want %q, have %q", want, have)
}
Expand Down Expand Up @@ -317,7 +398,7 @@ func TestTraceClient(t *testing.T) {
}

if want, have := map[string]interface{}{
ext.SpanKindRPCClient.Key: ext.SpanKindRPCClient.Value,
otext.SpanKindRPCClient.Key: otext.SpanKindRPCClient.Value,
}, span.Tags(); fmt.Sprint(want) != fmt.Sprint(have) {
t.Fatalf("Want %q, have %q", want, have)
}
Expand Down

0 comments on commit 5cab590

Please sign in to comment.