Merge pull request #55 from snabble/use-tracex

Use tracex for all otel needs

Author: tnicolaisen-snabble

.travis.yml

@@ -1,6 +1,6 @@
 language: go
 go:
-- 1.18.x
+- 1.19.x
 before_install:
 - go install honnef.co/go/tools/cmd/staticcheck@latest
 script:

go.mod

@@ -1,26 +1,27 @@
 module github.com/snabble/go-logging/v2
 
-go 1.18
+go 1.19
 
 require (
 	github.com/sirupsen/logrus v1.9.0
 	github.com/stretchr/testify v1.8.1
-	github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.18
+	github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.20
 	go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.38.0
 	go.opentelemetry.io/otel v1.12.0
-	go.opentelemetry.io/otel/sdk v1.11.1
+	go.opentelemetry.io/otel/sdk v1.11.2
 	go.opentelemetry.io/otel/trace v1.12.0
-	golang.org/x/xerrors v0.0.0-20220907171357-04be3eba64a2
 )
 
 require (
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/felixge/httpsnoop v1.0.3 // indirect
 	github.com/go-logr/logr v1.2.3 // indirect
 	github.com/go-logr/stdr v1.2.2 // indirect
+	github.com/kr/text v0.2.0 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
-	github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.18 // indirect
+	github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.20 // indirect
 	go.opentelemetry.io/otel/metric v0.35.0 // indirect
 	golang.org/x/sys v0.4.0 // indirect
+	gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 )

go.sum

@@ -1,3 +1,4 @@
+github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 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=
@@ -9,6 +10,12 @@ github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbV
 github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag=
 github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE=
 github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
+github.com/kr/pretty v0.2.1 h1:Fmg33tUaq4/8ym9TJN1x7sLJnHVwhP33CNkpYV/7rwI=
+github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
+github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
+github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
+github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
+github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
 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/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0=
@@ -21,27 +28,26 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/
 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=
-github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.18 h1:3UVwJbeF2xV7r7rB1KLGsYlZGoF9P25VkyilyI5zqmY=
-github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.18/go.mod h1:1jmEHPb6FL22RcHSsVaPg9UH1IFOV0hGFdZYgkyJeag=
-github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.18 h1:zsEhOhAfpNejDoJQi0gLsnN1bf3x2h7dTF7XNS2MJPE=
-github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.18/go.mod h1:7le+eIjcOjMMZ7QJqmzZFxcmZNvIK1qBdsYkHzaYuMU=
+github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.20 h1:g8zAGsjsiJzbtFc8S7n0do48LIK7k7MtBNmTKftDXzM=
+github.com/uptrace/opentelemetry-go-extra/otellogrus v0.1.20/go.mod h1:S3D8uTHdX/koXbokZkn+mkKbMLHhUGKxKzhGK6lDVnY=
+github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.20 h1:+4xV/g5ncPPNcHUBbj9JKEuee7EggpDlAnJIHnBymOo=
+github.com/uptrace/opentelemetry-go-extra/otelutil v0.1.20/go.mod h1:V0FSB+VaY2zak6iCOf2jmyA5YOj6LSB/X+AdkBUENVg=
 go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.38.0 h1:rTxmym+VN9f6ajzNtITVgyvZrNbpLt3NHr3suLLHLEQ=
 go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.38.0/go.mod h1:w6xNm+kC506KNs5cknSHal6dtdRnc4uema0uN9GSQc0=
 go.opentelemetry.io/otel v1.12.0 h1:IgfC7kqQrRccIKuB7Cl+SRUmsKbEwSGPr0Eu+/ht1SQ=
 go.opentelemetry.io/otel v1.12.0/go.mod h1:geaoz0L0r1BEOR81k7/n9W4TCXYCJ7bPO7K374jQHG0=
 go.opentelemetry.io/otel/metric v0.35.0 h1:aPT5jk/w7F9zW51L7WgRqNKDElBdyRLGuBtI5MX34e8=
 go.opentelemetry.io/otel/metric v0.35.0/go.mod h1:qAcbhaTRFU6uG8QM7dDo7XvFsWcugziq/5YI065TokQ=
-go.opentelemetry.io/otel/sdk v1.11.1 h1:F7KmQgoHljhUuJyA+9BiU+EkJfyX5nVVF4wyzWZpKxs=
-go.opentelemetry.io/otel/sdk v1.11.1/go.mod h1:/l3FE4SupHJ12TduVjUkZtlfFqDCQJlOlithYrdktys=
+go.opentelemetry.io/otel/sdk v1.11.2 h1:GF4JoaEx7iihdMFu30sOyRx52HDHOkl9xQ8SMqNXUiU=
+go.opentelemetry.io/otel/sdk v1.11.2/go.mod h1:wZ1WxImwpq+lVRo4vsmSOxdd+xwoUJ6rqyLc3SyX9aU=
 go.opentelemetry.io/otel/trace v1.12.0 h1:p28in++7Kd0r2d8gSt931O57fdjUyWxkVbESuILAeUc=
 go.opentelemetry.io/otel/trace v1.12.0/go.mod h1:pHlgBynn6s25qJ2szD+Bv+iwKJttjHSI3lUAyf0GNuQ=
 golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.4.0 h1:Zr2JFtRQNX3BCZ8YtxRE9hNJYC8J6I1MVbMg6owUp18=
 golang.org/x/sys v0.4.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/xerrors v0.0.0-20220907171357-04be3eba64a2 h1:H2TDz8ibqkAF6YGhCdN3jS9O0/s90v0rJh3X/OLHEUk=
-golang.org/x/xerrors v0.0.0-20220907171357-04be3eba64a2/go.mod h1:K8+ghG5WaK9qNqU5K3HdILfMLy1f3aNYFI/wnl100a8=
-gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk=
+gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q=
 gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
 gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
 gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

helper.go

@@ -10,7 +10,7 @@ import (
 	"time"
 
 	"github.com/sirupsen/logrus"
-	"github.com/uptrace/opentelemetry-go-extra/otellogrus"
+	"github.com/snabble/go-logging/v2/tracex"
 )
 
 // AccessLogCookiesBlacklist The list of cookies which should not be logged
@@ -58,13 +58,7 @@ func SetWithConfig(level string, config *LogConfig) error {
 	}
 
 	if config.EnableTraces {
-		logger.AddHook(otellogrus.NewHook(otellogrus.WithLevels(
-			logrus.PanicLevel,
-			logrus.FatalLevel,
-			logrus.ErrorLevel,
-			logrus.WarnLevel,
-			logrus.InfoLevel,
-		)))
+		logger.AddHook(tracex.NewLogrusHook())
 	}
 
 	logger.Level = l

log_middleware.go

@@ -8,7 +8,7 @@ import (
 	"strings"
 	"time"
 
-	"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
+	"github.com/snabble/go-logging/v2/tracex"
 )
 
 type LogMiddleware struct {
@@ -17,7 +17,7 @@ type LogMiddleware struct {
 
 func NewLogMiddleware(next http.Handler) http.Handler {
 	if Log.config.EnableTraces {
-		return otelhttp.NewHandler(&LogMiddleware{Next: next}, "common")
+		return tracex.NewHandler(&LogMiddleware{Next: next}, "common")
 	}
 	return &LogMiddleware{Next: next}
 }

logger_test.go

@@ -4,14 +4,14 @@ import (
 	"bytes"
 	"encoding/json"
 	"errors"
+	"fmt"
 	"net/http"
 	"os"
 	"testing"
 	"time"
 
 	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
-	"golang.org/x/xerrors"
 )
 
 type logRecord struct {
@@ -62,12 +62,12 @@ func Test_Logger_WithError(t *testing.T) {
 	Log.Out = b
 
 	err := func() error {
-		return xerrors.Errorf("found an error: %w", errors.New("an error occurred"))
+		return fmt.Errorf("found an error: %w", errors.New("an error occurred"))
 	}()
 	Log.WithError(err).Error("oops")
 
 	// print(b.String())
-	a.Regexp(`^time.* level\=error msg\=oops error\="found an error: an error occurred" stacktrace\=".*"`, b.String())
+	a.Regexp(`^time.* level\=error msg\=oops error\="found an error: an error occurred"`, b.String())
 }
 
 func Test_Logger_Call(t *testing.T) {

logstash_formatter.go

@@ -7,7 +7,7 @@ import (
 	"time"
 
 	"github.com/sirupsen/logrus"
-	"go.opentelemetry.io/otel/trace"
+	"github.com/snabble/go-logging/v2/tracex"
 )
 
 // Taken from github.com/bshuster-repo/logrus-logstash-hook
@@ -78,11 +78,7 @@ func (f *LogstashFormatter) FormatWithPrefix(entry *logrus.Entry, prefix string)
 		fields["type"] = f.Type
 	}
 
-	spanContext := trace.SpanContextFromContext(entry.Context)
-	if spanContext.IsValid() {
-		fields["trace"] = spanContext.TraceID()
-		fields["span"] = spanContext.SpanID()
-	}
+	tracex.TraceAndSpan(entry.Context, fields)
 
 	serialized, err := json.Marshal(fields)
 	if err != nil {

trace_provider_test.go

@@ -0,0 +1,57 @@
+package logging
+
+import (
+	"bytes"
+	"context"
+	"testing"
+
+	"github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus/hooks/writer"
+	"github.com/snabble/go-logging/v2/tracex"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"go.opentelemetry.io/otel"
+	"go.opentelemetry.io/otel/trace"
+)
+
+func Test_NewGlobalNoopTraceProvider_SetsTheGlobalProvider(t *testing.T) {
+	capture := capturingLogger(t)
+	defer func() { _ = Set("info", true) }()
+
+	provider := tracex.NewGlobalNoopTraceProvider("sampleApp", "v1.0.0")
+
+	ctx, span := startSpan()
+	defer span.End()
+	Log.WithContext(ctx).Info("meee")
+
+	require.NoError(t, provider.Shutdown(context.Background()))
+	assert.NotContains(t, capture.String(), "00000000000000000000000000000000")
+	assert.Contains(t, capture.String(), "trace")
+	assert.Contains(t, capture.String(), "span")
+}
+
+func Test_NewGlobalNoopTraceProvider_DoesNotTraceIfNotActivated(t *testing.T) {
+	capture := capturingLogger(t)
+	defer func() { _ = Set("info", true) }()
+
+	ctx, span := startSpan()
+	defer span.End()
+	Log.WithContext(ctx).Info("meee")
+
+	assert.NotContains(t, capture.String(), "trace")
+	assert.NotContains(t, capture.String(), "span")
+}
+
+func startSpan() (context.Context, trace.Span) {
+	return otel.Tracer("global").Start(context.Background(), "test")
+}
+
+func capturingLogger(t *testing.T) *bytes.Buffer {
+	t.Helper()
+
+	capture := &bytes.Buffer{}
+	err := SetWithConfig("info", &LogConfig{EnableTraces: true, EnableTextLogging: false})
+	require.NoError(t, err)
+	Log.Hooks.Add(&writer.Hook{Writer: capture, LogLevels: logrus.AllLevels})
+	return capture
+}

tracex/datamap/propagator.go

@@ -0,0 +1,58 @@
+package datamap
+
+import (
+	"context"
+	"strings"
+
+	"github.com/snabble/go-logging/v2/tracex/propagation"
+)
+
+type Propagator struct {
+	propagation propagation.TraceContext
+}
+
+func NewPropagator() *Propagator {
+	return &Propagator{propagation: propagation.TraceContext{}}
+}
+
+// Container contains a datamap
+type Container interface {
+	GetDataMap() map[string]string
+}
+
+func (p *Propagator) Extract(ctx context.Context, owner Container) context.Context {
+	return p.propagation.Extract(ctx, dataMap(owner.GetDataMap()))
+}
+
+func (p *Propagator) Inject(ctx context.Context) map[string]string {
+	carrier := dataMap{}
+	p.propagation.Inject(ctx, carrier)
+	return carrier
+}
+
+const tracingPrefix = "__tracing__"
+
+type dataMap map[string]string
+
+func (dm dataMap) Get(key string) string {
+	value, ok := dm[tracingPrefix+key]
+	if !ok {
+		return ""
+	}
+	return value
+}
+
+func (dm dataMap) Set(key string, value string) {
+	dm[tracingPrefix+key] = value
+}
+
+func (dm dataMap) Keys() []string {
+	keys := make([]string, 0, len(dm))
+	for key := range dm {
+		if !strings.HasPrefix(key, tracingPrefix) {
+			continue
+		}
+		keys = append(keys, strings.TrimPrefix(key, tracingPrefix))
+	}
+	return keys
+}

tracex/datamap/propagator_test.go

@@ -0,0 +1,74 @@
+package datamap
+
+import (
+	"context"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"go.opentelemetry.io/otel/trace"
+)
+
+const (
+	traceID      = "11000000000000000000000000000000"
+	spanID       = "0100000000000000"
+	traceAndSpan = "00-11000000000000000000000000000000-0100000000000000-00"
+)
+
+var (
+	spanContext = trace.NewSpanContext(
+		trace.SpanContextConfig{
+			TraceID: trace.TraceID{0x11},
+			SpanID:  trace.SpanID{0x01},
+		})
+)
+
+func Test_Inject_DataMapIsFilledWithTrace(t *testing.T) {
+	ctx := trace.ContextWithRemoteSpanContext(context.Background(), spanContext)
+	ctx, _ = traceProvider().
+		Tracer("__traced_app__").Start(ctx, "test")
+
+	inject := propagator().Inject(ctx)
+
+	container := dataMap(inject)
+	assert.Equal(t, container.Keys(), []string{"traceparent"})
+	assert.Equal(t, traceAndSpan, container.Get("traceparent"))
+}
+
+type someDataMapContainer struct {
+	dm map[string]string
+}
+
+func (s someDataMapContainer) GetDataMap() map[string]string {
+	return s.dm
+}
+
+func Test_Extract_PopulatesContext(t *testing.T) {
+	workItem := someDataMapContainer{dm: map[string]string{"__tracing__traceparent": traceAndSpan}}
+
+	ctx := context.Background()
+	extractedCtx := propagator().Extract(ctx, workItem)
+
+	span := trace.SpanContextFromContext(extractedCtx)
+	assert.True(t, span.IsRemote())
+	assert.Equal(t, traceID, span.TraceID().String())
+	assert.Equal(t, spanID, span.SpanID().String())
+}
+
+func Test_Extract_DoesNotFailOnEmptyDataMap(t *testing.T) {
+	workItem := someDataMapContainer{dm: map[string]string{}}
+
+	ctx := context.Background()
+	extractedCtx := propagator().Extract(ctx, workItem)
+
+	span := trace.SpanContextFromContext(extractedCtx)
+	assert.False(t, span.IsRemote())
+	assert.False(t, span.IsValid())
+}
+
+func propagator() *Propagator {
+	return NewPropagator()
+}
+
+func traceProvider() trace.TracerProvider {
+	return trace.NewNoopTracerProvider()
+}