From 915445205fae6ef5c132cad7467e1704cb68c660 Mon Sep 17 00:00:00 2001 From: yabuchan Date: Sun, 3 Jul 2022 23:30:10 +0900 Subject: [PATCH 1/7] add logic for otel --- go.mod | 7 +- go.sum | 22 +- trace/opentelemetry/opentelemetry.go | 276 +++++++++++ trace/opentelemetry/opentelemetry_test.go | 572 ++++++++++++++++++++++ 4 files changed, 871 insertions(+), 6 deletions(-) create mode 100644 trace/opentelemetry/opentelemetry.go create mode 100644 trace/opentelemetry/opentelemetry_test.go diff --git a/go.mod b/go.mod index 308f45073..ba24693ce 100644 --- a/go.mod +++ b/go.mod @@ -9,7 +9,7 @@ require ( github.com/docker/spdystream v0.0.0-20170912183627-bc6354cbbc29 // indirect github.com/elazarl/goproxy v0.0.0-20190421051319-9d40249d3c2f // indirect github.com/elazarl/goproxy/ext v0.0.0-20190711103511-473e67f1d7d2 // indirect - github.com/google/go-cmp v0.5.2 + github.com/google/go-cmp v0.5.7 github.com/gorilla/mux v1.7.3 github.com/mitchellh/go-homedir v1.1.0 github.com/pkg/errors v0.9.1 @@ -18,8 +18,11 @@ require ( github.com/spf13/cobra v1.0.0 github.com/spf13/pflag v1.0.5 go.opencensus.io v0.22.2 + go.opentelemetry.io/otel v1.7.0 + go.opentelemetry.io/otel/sdk v1.7.0 + go.opentelemetry.io/otel/trace v1.7.0 golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9 - golang.org/x/sys v0.0.0-20201112073958-5cba982894dd + golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7 golang.org/x/time v0.0.0-20200630173020-3af7569d3a1e google.golang.org/api v0.15.1 // indirect gotest.tools v2.2.0+incompatible diff --git a/go.sum b/go.sum index 5910cae94..cc1bfa209 100644 --- a/go.sum +++ b/go.sum @@ -127,8 +127,12 @@ github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas= github.com/go-logr/logr v0.2.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU= -github.com/go-logr/logr v0.3.0 h1:q4c+kbcR0d5rSurhBR8dIgieOaYpXtsdTYfx22Cu6rs= github.com/go-logr/logr v0.3.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU= +github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= +github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +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/go-logr/zapr v0.2.0 h1:v6Ji8yBW77pva6NkJKQdHLAJKrIJKRHz0RXwPqCHSR4= github.com/go-logr/zapr v0.2.0/go.mod h1:qhKdvif7YF5GI9NWEpyxTSSBdGmzkNguibrdCNVPunU= github.com/go-openapi/analysis v0.0.0-20180825180245-b006789cd277/go.mod h1:k70tL6pCuVxPJOHXQ+wIac1FUrvNkHolPie/cLEU6hI= @@ -214,8 +218,9 @@ github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5a github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= -github.com/google/go-cmp v0.5.2 h1:X2ev0eStA3AbceY54o37/0PQ/UWqKEiiO2dKL5OPaFM= github.com/google/go-cmp v0.5.2/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= +github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o= +github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE= github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= github.com/google/gofuzz v1.1.0 h1:Hsa8mG0dQ46ij8Sl2AYJDUv1oA9/d6Vk+3LG99Oe02g= github.com/google/gofuzz v1.1.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= @@ -399,8 +404,9 @@ github.com/stretchr/objx v0.2.0/go.mod h1:qt09Ya8vawLte6SNmTgCsAVtYtaKzEcn8ATUoH github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= -github.com/stretchr/testify v1.5.1 h1:nOGnQDM7FYENwehXlg/kFVnos3rEvtKTjRvOWSzb6H4= github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= +github.com/stretchr/testify v1.7.1 h1:5TQK59W5E3v0r2duFAb7P95B6hEeOyEnHRa8MjYSMTY= +github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/tidwall/pretty v1.0.0/go.mod h1:XNkn88O1ChpSDQmQeStsy+sBenx6DDtFZJxhVysOjyk= github.com/tmc/grpc-websocket-proxy v0.0.0-20170815181823-89b8d40f7ca8/go.mod h1:ncp9v5uamzpCO7NfCPTXjqaC+bZgJeR0sMTm6dMHP7U= github.com/tmc/grpc-websocket-proxy v0.0.0-20190109142713-0ad062ec5ee5/go.mod h1:ncp9v5uamzpCO7NfCPTXjqaC+bZgJeR0sMTm6dMHP7U= @@ -424,6 +430,12 @@ go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.0/go.mod h1:+kGneAE2xo2IficOXnaByMWTGM9T73dGwxeWcUqIpI8= go.opencensus.io v0.22.2 h1:75k/FF0Q2YM8QYo07VPddOLBslDt1MZOdEslOHvmzAs= go.opencensus.io v0.22.2/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw= +go.opentelemetry.io/otel v1.7.0 h1:Z2lA3Tdch0iDcrhJXDIlC94XE+bxok1F9B+4Lz/lGsM= +go.opentelemetry.io/otel v1.7.0/go.mod h1:5BdUoMIz5WEs0vt0CUEMtSSaTSHBBVwrhnz7+nrD5xk= +go.opentelemetry.io/otel/sdk v1.7.0 h1:4OmStpcKVOfvDOgCt7UriAPtKolwIhxpnSNI/yK+1B0= +go.opentelemetry.io/otel/sdk v1.7.0/go.mod h1:uTEOTwaqIVuTGiJN7ii13Ibp75wJmYUDe374q6cZwUU= +go.opentelemetry.io/otel/trace v1.7.0 h1:O37Iogk1lEkMRXewVtZ1BBTVn5JEp8GrJvP92bJqC6o= +go.opentelemetry.io/otel/trace v1.7.0/go.mod h1:fzLSB9nqR2eXzxPXb2JW9IKE+ScyXA48yyE4TNvoHqU= go.uber.org/atomic v1.3.2/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.6.0 h1:Ezj3JGmsOnG1MoRWQkPBsKLe9DwWD9QeXzTRzzldNVk= @@ -546,8 +558,9 @@ golang.org/x/sys v0.0.0-20200519105757-fe76b779f299/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20200615200032-f1bc736245b1/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200622214017-ed371f2e16b4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20201112073958-5cba982894dd h1:5CtCZbICpIOFdgO940moixOPjc0178IU44m4EjOO5IY= golang.org/x/sys v0.0.0-20201112073958-5cba982894dd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7 h1:iGu644GcxtEcrInvDsQRCwJjtCIOlT2V7IRt6ah2Whw= +golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.1-0.20180807135948-17ff2d5776d2/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk= @@ -669,6 +682,7 @@ gopkg.in/yaml.v2 v2.2.5/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v2 v2.3.0 h1:clyUAQHOM3G0M3f5vQj7LuJrETvjVot3Z5el9nffUtU= gopkg.in/yaml.v2 v2.3.0/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.0-20200615113413-eeeca48fe776 h1:tQIYjPdBoyREyB9XMu+nnTclpTYkz2zFM+lzLJFO4gQ= gopkg.in/yaml.v3 v3.0.0-20200615113413-eeeca48fe776/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gotest.tools v2.2.0+incompatible h1:VsBPFP1AI068pPrMxtb/S8Zkgf9xEmTLJjfM+P5UIEo= diff --git a/trace/opentelemetry/opentelemetry.go b/trace/opentelemetry/opentelemetry.go new file mode 100644 index 000000000..9bcd5b344 --- /dev/null +++ b/trace/opentelemetry/opentelemetry.go @@ -0,0 +1,276 @@ +// Copyright © 2022 The virtual-kubelet authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package openTelemetry implements a github.com/virtual-kubelet/virtual-kubelet/trace.Tracer +// using openTelemetry as a backend. +// +// Use this by setting `trace.T = Adapter{}` +// +// For customizing trace provider used in Adapter, set trace provider by +//`otel.SetTracerProvider(*sdktrace.TracerProvider)`. Examples of customize are setting service name, +// use your own exporter (e.g. jaeger, otlp, prometheus, zipkin, and stdout) etc. Do not forget +// to call TracerProvider.Shutdown() when you create your TracerProvider to avoid memory leak. +package openTelemetry + +import ( + "context" + "fmt" + "sync" + + "go.opentelemetry.io/otel/codes" + + "github.com/virtual-kubelet/virtual-kubelet/log" + "github.com/virtual-kubelet/virtual-kubelet/trace" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + ot "go.opentelemetry.io/otel/trace" +) + +type logLevel string + +const ( + lDebug logLevel = "DEBUG" + lInfo logLevel = "INFO" + lWarn logLevel = "WARN" + lErr logLevel = "ERROR" + lFatal logLevel = "FATAL" +) + +func (l logLevel) string() string { + return string(l) +} + +// Adapter implements the trace.Tracer interface for openTelemetry +type Adapter struct{} + +// StartSpan creates a new span from openTelemetry using the given name. +func (Adapter) StartSpan(ctx context.Context, name string) (context.Context, trace.Span) { + ctx, ots := otel.Tracer(name).Start(ctx, name) + l := log.G(ctx).WithField("method", name) + + s := &span{s: ots, l: l} + ctx = log.WithLogger(ctx, s.Logger()) + + return ctx, s +} + +type span struct { + mu sync.Mutex + s ot.Span + l log.Logger +} + +func (s *span) End() { + s.s.End() +} + +func (s *span) SetStatus(err error) { + if !s.s.IsRecording() { + return + } + + if err == nil { + s.s.SetStatus(codes.Ok, "") + } else { + s.s.SetStatus(codes.Error, err.Error()) + } +} + +func (s *span) WithField(ctx context.Context, key string, val interface{}) context.Context { + s.mu.Lock() + s.l = s.l.WithField(key, val) + ctx = log.WithLogger(ctx, &logger{s: s.s, l: s.l}) + s.mu.Unlock() + + if s.s.IsRecording() { + s.s.SetAttributes(makeAttribute(key, val)) + } + + return ctx +} + +func (s *span) WithFields(ctx context.Context, f log.Fields) context.Context { + s.mu.Lock() + s.l = s.l.WithFields(f) + ctx = log.WithLogger(ctx, &logger{s: s.s, l: s.l}) + s.mu.Unlock() + + if s.s.IsRecording() { + attrs := make([]attribute.KeyValue, 0, len(f)) + for k, v := range f { + attrs = append(attrs, makeAttribute(k, v)) + } + s.s.SetAttributes(attrs...) + } + return ctx +} + +func (s *span) Logger() log.Logger { + return &logger{s: s.s, l: s.l} +} + +type logger struct { + s ot.Span + l log.Logger + a []attribute.KeyValue +} + +func (l *logger) Debug(args ...interface{}) { + l.logEvent(lDebug, args...) +} + +func (l *logger) Debugf(f string, args ...interface{}) { + l.logEventf(lDebug, f, args...) +} + +func (l *logger) Info(args ...interface{}) { + l.logEvent(lInfo, args...) +} + +func (l *logger) Infof(f string, args ...interface{}) { + l.logEventf(lInfo, f, args...) +} + +func (l *logger) Warn(args ...interface{}) { + l.logEvent(lWarn, args...) +} + +func (l *logger) Warnf(f string, args ...interface{}) { + l.logEventf(lWarn, f, args...) +} + +func (l *logger) Error(args ...interface{}) { + l.logEvent(lErr, args...) +} + +func (l *logger) Errorf(f string, args ...interface{}) { + l.logEventf(lErr, f, args...) +} + +func (l *logger) Fatal(args ...interface{}) { + l.logEvent(lFatal, args...) +} + +func (l *logger) Fatalf(f string, args ...interface{}) { + l.logEventf(lFatal, f, args...) +} + +func (l *logger) logEvent(ll logLevel, args ...interface{}) { + msg := fmt.Sprint(args...) + switch ll { + case lDebug: + l.l.Debug(msg) + case lInfo: + l.l.Info(msg) + case lWarn: + l.l.Warn(msg) + case lErr: + l.l.Error(msg) + case lFatal: + l.l.Fatal(msg) + } + + if !l.s.IsRecording() { + return + } + + //TODO Add log event to span once it is available. + // The Logs signal is not supported in opentelemetry-go yet. + // ref: https://github.com/open-telemetry/opentelemetry-go +} + +func (l *logger) logEventf(ll logLevel, f string, args ...interface{}) { + switch ll { + case lDebug: + l.l.Debugf(f, args...) + case lInfo: + l.l.Infof(f, args...) + case lWarn: + l.l.Warnf(f, args...) + case lErr: + l.l.Errorf(f, args...) + case lFatal: + l.l.Fatalf(f, args...) + } + + if !l.s.IsRecording() { + return + } + + //TODO Add log event to span once it is available. + // The Logs signal is not supported in opentelemetry-go yet. + // ref: https://github.com/open-telemetry/opentelemetry-go +} + +func (l *logger) WithError(err error) log.Logger { + if err == nil { + return l + } + return l.WithField("err", err) +} + +func (l *logger) WithField(k string, value interface{}) log.Logger { + var attrs []attribute.KeyValue + if l.s.IsRecording() { + attrs = make([]attribute.KeyValue, len(l.a)+1) + copy(attrs, l.a) + attrs[len(attrs)-1] = makeAttribute(k, value) + } + l.a = attrs + return &logger{s: l.s, a: attrs, l: l.l.WithField(k, value)} +} + +func (l *logger) WithFields(fields log.Fields) log.Logger { + var attrs []attribute.KeyValue + if l.s.IsRecording() { + attrs = make([]attribute.KeyValue, len(l.a), len(l.a)+len(fields)) + copy(attrs, l.a) + for k, v := range fields { + attrs = append(attrs, makeAttribute(k, v)) + } + } + l.a = attrs + return &logger{s: l.s, a: attrs, l: l.l.WithFields(fields)} +} + +func makeAttribute(key string, val interface{}) (attr attribute.KeyValue) { + switch v := val.(type) { + case string: + return attribute.String(key, v) + case []string: + return attribute.StringSlice(key, v) + case fmt.Stringer: + return attribute.Stringer(key, v) + case int: + return attribute.Int(key, v) + case []int: + return attribute.IntSlice(key, v) + case int64: + return attribute.Int64(key, v) + case float64: + return attribute.Float64(key, v) + case []float64: + return attribute.Float64Slice(key, v) + case []int64: + return attribute.Int64Slice(key, v) + case bool: + return attribute.Bool(key, v) + case []bool: + return attribute.BoolSlice(key, v) + case error: + return attribute.String(key, v.Error()) + default: + return attribute.String(key, fmt.Sprintf("%+v", val)) + } +} diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go new file mode 100644 index 000000000..1bae18b3b --- /dev/null +++ b/trace/opentelemetry/opentelemetry_test.go @@ -0,0 +1,572 @@ +// Copyright © 2022 The virtual-kubelet authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package openTelemetry + +import ( + "context" + "sync" + "testing" + "time" + + "github.com/pkg/errors" + "github.com/virtual-kubelet/virtual-kubelet/log" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/sdk/resource" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + semconv "go.opentelemetry.io/otel/semconv/v1.10.0" + "gotest.tools/assert" + "gotest.tools/assert/cmp" + //"github.com/virtual-kubelet/virtual-kubelet/trace" + //octrace "go.opencensus.io/trace" + //"gotest.tools/assert" + //is "gotest.tools/assert/cmp" +) + +func TestStartSpan(t *testing.T) { + t.Run("addField", func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + a := Adapter{} + ctx, s := a.StartSpan(ctx, "name") + s.End() + }) +} + +func TestSetStatus(t *testing.T) { + testCases := []struct { + description string + spanName string + inputStatus error + expectedCode codes.Code + expectedDescription string + }{ + { + description: "error status", + spanName: "test", + inputStatus: errors.New("fake msg"), + expectedCode: codes.Error, + expectedDescription: "fake msg", + }, { + description: "non-error status", + spanName: "test", + inputStatus: nil, + expectedCode: codes.Ok, + expectedDescription: "", + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, e := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, ots := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := log.G(ctx).WithField("method", tt.spanName) + + s := &span{s: ots, l: l} + s.SetStatus(tt.inputStatus) + assert.Assert(t, s.s.IsRecording()) + + s.End() + + assert.Assert(t, !s.s.IsRecording()) + assert.Assert(t, e.status.Code == tt.expectedCode) + assert.Assert(t, e.status.Description == tt.expectedDescription) + + s.SetStatus(tt.inputStatus) // should not be panic even if span is ended. + }) + } +} + +func TestWithField(t *testing.T) { + type field struct { + key string + value interface{} + } + + testCases := []struct { + description string + spanName string + fields []field + expectedAttributes []attribute.KeyValue + }{ + { + description: "single field", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "multiple unique fields", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}, {key: "testKey2", value: "value2"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}, {Key: "testKey2", Value: attribute.StringValue("value2")}}, + }, { + description: "duplicated fields", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}, {key: "testKey1", value: "value2"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value2")}}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, e := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, ots := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := log.G(ctx).WithField("method", tt.spanName) + s := &span{s: ots, l: l} + + for _, f := range tt.fields { + ctx = s.WithField(ctx, f.key, f.value) + } + s.End() + + assert.Assert(t, len(e.attributes) == len(tt.expectedAttributes)) + for i, a := range tt.expectedAttributes { + assert.Assert(t, e.attributes[i].Key == a.Key) + assert.Assert(t, e.attributes[i].Value == a.Value) + } + }) + } +} + +func TestWithFields(t *testing.T) { + testCases := []struct { + description string + spanName string + fields log.Fields + expectedAttributes []attribute.KeyValue + }{ + { + description: "single field", + spanName: "test", + fields: log.Fields{"testKey1": "value1"}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "multiple unique fields", + spanName: "test", + fields: log.Fields{"testKey1": "value1", "testKey2": "value2"}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}, {Key: "testKey2", Value: attribute.StringValue("value2")}}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, e := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, ots := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := log.G(ctx).WithField("method", tt.spanName) + s := &span{s: ots, l: l} + + ctx = s.WithFields(ctx, tt.fields) + s.End() + + assert.Assert(t, len(e.attributes) == len(tt.expectedAttributes)) + for i, a := range tt.expectedAttributes { + assert.Assert(t, e.attributes[i].Key == a.Key) + assert.Assert(t, e.attributes[i].Value == a.Value) + } + }) + } +} + +func TestLog(t *testing.T) { + testCases := []struct { + description string + spanName string + logLevel logLevel + fields log.Fields + msg string + expectedAttributes []attribute.KeyValue + }{ + { + description: "debug", + spanName: "test", + logLevel: lDebug, + fields: log.Fields{"testKey1": "value1"}, + msg: "message", + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "info", + spanName: "test", + logLevel: lInfo, + fields: log.Fields{"testKey1": "value1"}, + msg: "message", + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "warn", + spanName: "test", + logLevel: lWarn, + fields: log.Fields{"testKey1": "value1"}, + msg: "message", + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "error", + spanName: "test", + logLevel: lErr, + fields: log.Fields{"testKey1": "value1"}, + msg: "message", + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "fatal", + spanName: "test", + logLevel: lFatal, + fields: log.Fields{"testKey1": "value1"}, + msg: "message", + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + switch tt.logLevel { + case lDebug: + l.WithFields(tt.fields).Debug(tt.msg) + case lInfo: + l.WithFields(tt.fields).Info(tt.msg) + case lWarn: + l.WithFields(tt.fields).Warn(tt.msg) + case lErr: + l.WithFields(tt.fields).Error(tt.msg) + case lFatal: + l.WithFields(tt.fields).Fatal(tt.msg) + } + s.End() + + //TODO add assertion with exporter here once logic for recoding log event is added. + assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + for i, a := range tt.expectedAttributes { + assert.Assert(t, l.a[i].Key == a.Key) + assert.Assert(t, l.a[i].Value == a.Value) + } + }) + } +} + +func TestLogf(t *testing.T) { + testCases := []struct { + description string + spanName string + logLevel logLevel + msg string + fields log.Fields + args []interface{} + expectedAttributes []attribute.KeyValue + }{ + { + description: "debug", + spanName: "test", + logLevel: lDebug, + msg: "k1: %s, k2: %v, k3: %d, k4: %v", + fields: map[string]interface{}{"k1": "test", "k2": []string{"test"}, "k3": 1, "k4": []int{1}}, + expectedAttributes: []attribute.KeyValue{ + attribute.String("k1", "test"), + attribute.StringSlice("k2", []string{"test"}), + attribute.Int("k3", 1), + attribute.IntSlice("k4", []int{1}), + }, + }, { + description: "info", + spanName: "test", + logLevel: lInfo, + msg: "k1: %d, k2: %v, k3: %f, k4: %v", + fields: map[string]interface{}{"k1": int64(3), "k2": []int64{4}, "k3": float64(2), "k4": []float64{4}}, + expectedAttributes: []attribute.KeyValue{ + attribute.Int64("k1", 1), + attribute.Int64Slice("k2", []int64{2}), + attribute.Float64("k3", 3), + attribute.Float64Slice("k2", []float64{4}), + }, + }, { + description: "warn", + spanName: "test", + logLevel: lWarn, + msg: "k1: %v", + fields: map[string]interface{}{"k1": map[int]int{1: 1}}, + expectedAttributes: []attribute.KeyValue{ + attribute.String("k1", "{1:1}"), + }, + }, { + description: "error", + spanName: "test", + logLevel: lErr, + msg: "k1: %t, k2: %v", + fields: map[string]interface{}{"k1": true, "k2": []bool{true}, "k3": errors.New("fake")}, + expectedAttributes: []attribute.KeyValue{ + attribute.Bool("k1", true), + attribute.BoolSlice("k2", []bool{true}), + attribute.String("k3", "fake"), + }, + }, { + description: "fatal", + spanName: "test", + logLevel: lFatal, + expectedAttributes: []attribute.KeyValue{}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + switch tt.logLevel { + case lDebug: + l.WithFields(tt.fields).Debugf(tt.msg, tt.args) + case lInfo: + l.WithFields(tt.fields).Infof(tt.msg, tt.args) + case lWarn: + l.WithFields(tt.fields).Warnf(tt.msg, tt.args) + case lErr: + l.WithFields(tt.fields).Errorf(tt.msg, tt.args) + case lFatal: + l.WithFields(tt.fields).Fatalf(tt.msg, tt.args) + } + s.End() + + //TODO add assertion with exporter here once logic for recoding log event is added. + assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + for _, a := range tt.expectedAttributes { + cmp.Contains(l.a, a) + } + }) + } +} + +func TestLogWithField(t *testing.T) { + type field struct { + key string + value interface{} + } + + testCases := []struct { + description string + spanName string + fields []field + expectedAttributes []attribute.KeyValue + }{ + { + description: "single field", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "multiple unique fields", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}, {key: "testKey2", value: "value2"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}, {Key: "testKey2", Value: attribute.StringValue("value2")}}, + }, { + description: "duplicated fields", + spanName: "test", + fields: []field{{key: "testKey1", value: "value1"}, {key: "testKey1", value: "value2"}}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}, {Key: "testKey2", Value: attribute.StringValue("value2")}}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + + for _, f := range tt.fields { + l.WithField(f.key, f.value).Info("") + } + s.End() + + assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + for _, a := range tt.expectedAttributes { + cmp.Contains(l.a, a) + } + }) + } +} + +func TestLogWithError(t *testing.T) { + testCases := []struct { + description string + spanName string + err error + expectedAttributes []attribute.KeyValue + }{ + { + description: "normal", + spanName: "test", + err: errors.New("fake"), + expectedAttributes: []attribute.KeyValue{{Key: "err", Value: attribute.StringValue("fake")}}, + }, { + description: "nil error", + spanName: "test", + err: nil, + expectedAttributes: []attribute.KeyValue{}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + + l.WithError(tt.err).Error("") + s.End() + + assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + for _, a := range tt.expectedAttributes { + cmp.Contains(l.a, a) + } + }) + } +} + +func TestLogWithFields(t *testing.T) { + testCases := []struct { + description string + spanName string + fields log.Fields + expectedAttributes []attribute.KeyValue + }{ + { + description: "single field", + spanName: "test", + fields: log.Fields{"testKey1": "value1"}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, + }, { + description: "multiple unique fields", + spanName: "test", + fields: log.Fields{"testKey1": "value1", "testKey2": "value2"}, + expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}, {Key: "testKey2", Value: attribute.StringValue("value2")}}, + }, + } + + for _, tt := range testCases { + t.Run(tt.description, func(t *testing.T) { + tearDown, p, _ := setupSuite() + defer tearDown(p) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + + l.WithFields(tt.fields).Debug("") + s.End() + + assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + for _, a := range tt.expectedAttributes { + cmp.Contains(l.a, a) + } + }) + } +} + +func setupSuite() (func(provider *sdktrace.TracerProvider), *sdktrace.TracerProvider, *fakeExporter) { + r := NewResource("virtual-kubelet", "1.2.3") + e := &fakeExporter{} + p := sdktrace.NewTracerProvider( + sdktrace.WithSyncer(e), + sdktrace.WithResource(r), + ) + otel.SetTracerProvider(p) + + // Return a function to teardown the test + return func(provider *sdktrace.TracerProvider) { + _ = p.Shutdown(context.Background()) + }, p, e +} + +func NewResource(name, version string) *resource.Resource { + return resource.NewWithAttributes( + semconv.SchemaURL, + semconv.ServiceNameKey.String(name), + semconv.ServiceVersionKey.String(version), + ) +} + +type fakeExporter struct { + sync.Mutex + attributes []attribute.KeyValue + // Links returns all the links the span has to other spans. + links []sdktrace.Link + // Events returns all the events that occurred within in the spans + // lifetime. + events []sdktrace.Event + // Status returns the spans status. + status sdktrace.Status +} + +func (f *fakeExporter) ExportSpans(_ context.Context, spans []sdktrace.ReadOnlySpan) (err error) { + f.Lock() + defer f.Unlock() + + f.attributes = make([]attribute.KeyValue, 0) + f.links = make([]sdktrace.Link, 0) + f.events = make([]sdktrace.Event, 0) + for _, s := range spans { + f.attributes = append(f.attributes, s.Attributes()...) + f.links = append(f.links, s.Links()...) + f.events = append(f.events, s.Events()...) + f.status = s.Status() + } + return +} + +func (f *fakeExporter) Shutdown(_ context.Context) (err error) { + f.attributes = make([]attribute.KeyValue, 0) + f.links = make([]sdktrace.Link, 0) + f.events = make([]sdktrace.Event, 0) + return +} From 853f9ead1c92068a3d4f63e0ecbe58685a62fe83 Mon Sep 17 00:00:00 2001 From: yabuchan Date: Mon, 4 Jul 2022 00:22:57 +0900 Subject: [PATCH 2/7] add sampler in test --- trace/opentelemetry/opentelemetry_test.go | 22 ++++++++-------------- 1 file changed, 8 insertions(+), 14 deletions(-) diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go index 1bae18b3b..e0533e453 100644 --- a/trace/opentelemetry/opentelemetry_test.go +++ b/trace/opentelemetry/opentelemetry_test.go @@ -30,10 +30,6 @@ import ( semconv "go.opentelemetry.io/otel/semconv/v1.10.0" "gotest.tools/assert" "gotest.tools/assert/cmp" - //"github.com/virtual-kubelet/virtual-kubelet/trace" - //octrace "go.opencensus.io/trace" - //"gotest.tools/assert" - //is "gotest.tools/assert/cmp" ) func TestStartSpan(t *testing.T) { @@ -93,7 +89,6 @@ func TestSetStatus(t *testing.T) { assert.Assert(t, !s.s.IsRecording()) assert.Assert(t, e.status.Code == tt.expectedCode) assert.Assert(t, e.status.Description == tt.expectedDescription) - s.SetStatus(tt.inputStatus) // should not be panic even if span is ended. }) } @@ -147,9 +142,8 @@ func TestWithField(t *testing.T) { s.End() assert.Assert(t, len(e.attributes) == len(tt.expectedAttributes)) - for i, a := range tt.expectedAttributes { - assert.Assert(t, e.attributes[i].Key == a.Key) - assert.Assert(t, e.attributes[i].Value == a.Value) + for _, a := range tt.expectedAttributes { + cmp.Contains(e.attributes, a) } }) } @@ -191,9 +185,8 @@ func TestWithFields(t *testing.T) { s.End() assert.Assert(t, len(e.attributes) == len(tt.expectedAttributes)) - for i, a := range tt.expectedAttributes { - assert.Assert(t, e.attributes[i].Key == a.Key) - assert.Assert(t, e.attributes[i].Value == a.Value) + for _, a := range tt.expectedAttributes { + cmp.Contains(e.attributes, a) } }) } @@ -272,9 +265,8 @@ func TestLog(t *testing.T) { //TODO add assertion with exporter here once logic for recoding log event is added. assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) - for i, a := range tt.expectedAttributes { - assert.Assert(t, l.a[i].Key == a.Key) - assert.Assert(t, l.a[i].Value == a.Value) + for _, a := range tt.expectedAttributes { + cmp.Contains(l.a, a) } }) } @@ -519,6 +511,7 @@ func setupSuite() (func(provider *sdktrace.TracerProvider), *sdktrace.TracerProv p := sdktrace.NewTracerProvider( sdktrace.WithSyncer(e), sdktrace.WithResource(r), + sdktrace.WithSampler(sdktrace.AlwaysSample()), ) otel.SetTracerProvider(p) @@ -538,6 +531,7 @@ func NewResource(name, version string) *resource.Resource { type fakeExporter struct { sync.Mutex + // attributes describe the aspects of the spans. attributes []attribute.KeyValue // Links returns all the links the span has to other spans. links []sdktrace.Link From 801b44543c3fb3da199ebaed186650a202e21f08 Mon Sep 17 00:00:00 2001 From: yabuchan Date: Mon, 4 Jul 2022 13:52:51 +0900 Subject: [PATCH 3/7] do not save attributes in logger, add fake logger in unit test --- trace/opentelemetry/opentelemetry.go | 8 +-- trace/opentelemetry/opentelemetry_test.go | 84 ++++++++++++++++++----- 2 files changed, 69 insertions(+), 23 deletions(-) diff --git a/trace/opentelemetry/opentelemetry.go b/trace/opentelemetry/opentelemetry.go index 9bcd5b344..dd50cee01 100644 --- a/trace/opentelemetry/opentelemetry.go +++ b/trace/opentelemetry/opentelemetry.go @@ -214,9 +214,6 @@ func (l *logger) logEventf(ll logLevel, f string, args ...interface{}) { } func (l *logger) WithError(err error) log.Logger { - if err == nil { - return l - } return l.WithField("err", err) } @@ -227,7 +224,6 @@ func (l *logger) WithField(k string, value interface{}) log.Logger { copy(attrs, l.a) attrs[len(attrs)-1] = makeAttribute(k, value) } - l.a = attrs return &logger{s: l.s, a: attrs, l: l.l.WithField(k, value)} } @@ -240,7 +236,6 @@ func (l *logger) WithFields(fields log.Fields) log.Logger { attrs = append(attrs, makeAttribute(k, v)) } } - l.a = attrs return &logger{s: l.s, a: attrs, l: l.l.WithFields(fields)} } @@ -269,6 +264,9 @@ func makeAttribute(key string, val interface{}) (attr attribute.KeyValue) { case []bool: return attribute.BoolSlice(key, v) case error: + if v == nil { + attribute.String(key, "") + } return attribute.String(key, v.Error()) default: return attribute.String(key, fmt.Sprintf("%+v", val)) diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go index e0533e453..cdb4a8b06 100644 --- a/trace/opentelemetry/opentelemetry_test.go +++ b/trace/opentelemetry/opentelemetry_test.go @@ -16,6 +16,7 @@ package openTelemetry import ( "context" + "strconv" "sync" "testing" "time" @@ -248,7 +249,8 @@ func TestLog(t *testing.T) { defer cancel() ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) - l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + fl := &fakeLogger{} + l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} switch tt.logLevel { case lDebug: l.WithFields(tt.fields).Debug(tt.msg) @@ -264,9 +266,9 @@ func TestLog(t *testing.T) { s.End() //TODO add assertion with exporter here once logic for recoding log event is added. - assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { - cmp.Contains(l.a, a) + cmp.Contains(fl.a, a) } }) } @@ -310,10 +312,11 @@ func TestLogf(t *testing.T) { description: "warn", spanName: "test", logLevel: lWarn, - msg: "k1: %v", - fields: map[string]interface{}{"k1": map[int]int{1: 1}}, + msg: "k1: %v, k2: %v", + fields: map[string]interface{}{"k1": map[int]int{1: 1}, "k2": num(1)}, expectedAttributes: []attribute.KeyValue{ attribute.String("k1", "{1:1}"), + attribute.Stringer("k2", num(1)), }, }, { description: "error", @@ -343,7 +346,8 @@ func TestLogf(t *testing.T) { defer cancel() ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) - l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + fl := &fakeLogger{} + l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} switch tt.logLevel { case lDebug: l.WithFields(tt.fields).Debugf(tt.msg, tt.args) @@ -359,10 +363,12 @@ func TestLogf(t *testing.T) { s.End() //TODO add assertion with exporter here once logic for recoding log event is added. - assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { - cmp.Contains(l.a, a) + cmp.Contains(fl.a, a) } + + l.Debugf(tt.msg, tt.args) // should not panic even if span is finished }) } } @@ -406,17 +412,21 @@ func TestLogWithField(t *testing.T) { defer cancel() ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) - l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + fl := &fakeLogger{} + l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} for _, f := range tt.fields { l.WithField(f.key, f.value).Info("") } s.End() - assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { - cmp.Contains(l.a, a) + cmp.Contains(fl.a, a) } + + l.Debug("") // should not panic even if span is finished + }) } } @@ -437,7 +447,7 @@ func TestLogWithError(t *testing.T) { description: "nil error", spanName: "test", err: nil, - expectedAttributes: []attribute.KeyValue{}, + expectedAttributes: []attribute.KeyValue{{Key: "err", Value: attribute.StringValue("")}}, }, } @@ -450,14 +460,15 @@ func TestLogWithError(t *testing.T) { defer cancel() ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) - l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + fl := &fakeLogger{} + l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} l.WithError(tt.err).Error("") s.End() - assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { - cmp.Contains(l.a, a) + cmp.Contains(fl.a, a) } }) } @@ -492,14 +503,15 @@ func TestLogWithFields(t *testing.T) { defer cancel() ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) - l := logger{s: s, l: log.G(ctx), a: make([]attribute.KeyValue, 0)} + fl := &fakeLogger{} + l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} l.WithFields(tt.fields).Debug("") s.End() - assert.Assert(t, len(l.a) == len(tt.expectedAttributes)) + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { - cmp.Contains(l.a, a) + cmp.Contains(fl.a, a) } }) } @@ -564,3 +576,39 @@ func (f *fakeExporter) Shutdown(_ context.Context) (err error) { f.events = make([]sdktrace.Event, 0) return } + +type fakeLogger struct { + a []attribute.KeyValue +} + +func (*fakeLogger) Debug(...interface{}) {} +func (*fakeLogger) Debugf(string, ...interface{}) {} +func (*fakeLogger) Info(...interface{}) {} +func (*fakeLogger) Infof(string, ...interface{}) {} +func (*fakeLogger) Warn(...interface{}) {} +func (*fakeLogger) Warnf(string, ...interface{}) {} +func (*fakeLogger) Error(...interface{}) {} +func (*fakeLogger) Errorf(string, ...interface{}) {} +func (*fakeLogger) Fatal(...interface{}) {} +func (*fakeLogger) Fatalf(string, ...interface{}) {} + +func (l *fakeLogger) WithField(k string, v interface{}) log.Logger { + l.a = append(l.a, makeAttribute(k, v)) + return l +} +func (l *fakeLogger) WithFields(fs log.Fields) log.Logger { + for k, v := range fs { + l.a = append(l.a, makeAttribute(k, v)) + } + return l +} +func (l *fakeLogger) WithError(err error) log.Logger { + l.a = append(l.a, makeAttribute("err", err)) + return l +} + +type num int + +func (i num) String() string { + return strconv.Itoa(int(i)) +} From 36397f80c252643fe851533b0d9f3c0536ec531b Mon Sep 17 00:00:00 2001 From: yabuchan Date: Mon, 4 Jul 2022 19:15:45 +0900 Subject: [PATCH 4/7] downgrade opentelemetry to avoid the library conflicts --- go.mod | 16 ++++++++++---- go.sum | 26 ++++++++++------------- trace/opentelemetry/opentelemetry_test.go | 2 +- 3 files changed, 24 insertions(+), 20 deletions(-) diff --git a/go.mod b/go.mod index ba24693ce..114ed18e9 100644 --- a/go.mod +++ b/go.mod @@ -9,7 +9,7 @@ require ( github.com/docker/spdystream v0.0.0-20170912183627-bc6354cbbc29 // indirect github.com/elazarl/goproxy v0.0.0-20190421051319-9d40249d3c2f // indirect github.com/elazarl/goproxy/ext v0.0.0-20190711103511-473e67f1d7d2 // indirect - github.com/google/go-cmp v0.5.7 + github.com/google/go-cmp v0.5.6 github.com/gorilla/mux v1.7.3 github.com/mitchellh/go-homedir v1.1.0 github.com/pkg/errors v0.9.1 @@ -18,9 +18,9 @@ require ( github.com/spf13/cobra v1.0.0 github.com/spf13/pflag v1.0.5 go.opencensus.io v0.22.2 - go.opentelemetry.io/otel v1.7.0 - go.opentelemetry.io/otel/sdk v1.7.0 - go.opentelemetry.io/otel/trace v1.7.0 + go.opentelemetry.io/otel v1.2.0 + go.opentelemetry.io/otel/sdk v1.2.0 + go.opentelemetry.io/otel/trace v1.2.0 golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9 golang.org/x/sys v0.0.0-20210423185535-09eb48e85fd7 golang.org/x/time v0.0.0-20200630173020-3af7569d3a1e @@ -35,3 +35,11 @@ require ( k8s.io/utils v0.0.0-20200912215256-4140de9c8800 sigs.k8s.io/controller-runtime v0.7.1 ) + +replace ( + // Note: Latest opentelemetry (v1.7.0) requires go-logr/logr v1.2 which conflicts with k8s.io/apimachinery. + // Safe to bump up to opentelemetry (v1.7.0) by removing these lines once k8s.io/apimachinery is updated. + go.opentelemetry.io/otel => go.opentelemetry.io/otel v1.2.0 + go.opentelemetry.io/otel/sdk => go.opentelemetry.io/otel/sdk v1.2.0 + go.opentelemetry.io/otel/trace => go.opentelemetry.io/otel/trace v1.2.0 +) diff --git a/go.sum b/go.sum index cc1bfa209..f93367b22 100644 --- a/go.sum +++ b/go.sum @@ -127,12 +127,8 @@ github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas= github.com/go-logr/logr v0.2.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU= +github.com/go-logr/logr v0.3.0 h1:q4c+kbcR0d5rSurhBR8dIgieOaYpXtsdTYfx22Cu6rs= github.com/go-logr/logr v0.3.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU= -github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= -github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0= -github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= -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/go-logr/zapr v0.2.0 h1:v6Ji8yBW77pva6NkJKQdHLAJKrIJKRHz0RXwPqCHSR4= github.com/go-logr/zapr v0.2.0/go.mod h1:qhKdvif7YF5GI9NWEpyxTSSBdGmzkNguibrdCNVPunU= github.com/go-openapi/analysis v0.0.0-20180825180245-b006789cd277/go.mod h1:k70tL6pCuVxPJOHXQ+wIac1FUrvNkHolPie/cLEU6hI= @@ -219,8 +215,8 @@ github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU= github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.2/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= -github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o= -github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE= +github.com/google/go-cmp v0.5.6 h1:BKbKCqvP6I+rmFHt06ZmyQtvB8xAkWdhFyr0ZUNZcxQ= +github.com/google/go-cmp v0.5.6/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= github.com/google/gofuzz v1.1.0 h1:Hsa8mG0dQ46ij8Sl2AYJDUv1oA9/d6Vk+3LG99Oe02g= github.com/google/gofuzz v1.1.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg= @@ -405,8 +401,8 @@ github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXf github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA= -github.com/stretchr/testify v1.7.1 h1:5TQK59W5E3v0r2duFAb7P95B6hEeOyEnHRa8MjYSMTY= -github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= github.com/tidwall/pretty v1.0.0/go.mod h1:XNkn88O1ChpSDQmQeStsy+sBenx6DDtFZJxhVysOjyk= github.com/tmc/grpc-websocket-proxy v0.0.0-20170815181823-89b8d40f7ca8/go.mod h1:ncp9v5uamzpCO7NfCPTXjqaC+bZgJeR0sMTm6dMHP7U= github.com/tmc/grpc-websocket-proxy v0.0.0-20190109142713-0ad062ec5ee5/go.mod h1:ncp9v5uamzpCO7NfCPTXjqaC+bZgJeR0sMTm6dMHP7U= @@ -430,12 +426,12 @@ go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.0/go.mod h1:+kGneAE2xo2IficOXnaByMWTGM9T73dGwxeWcUqIpI8= go.opencensus.io v0.22.2 h1:75k/FF0Q2YM8QYo07VPddOLBslDt1MZOdEslOHvmzAs= go.opencensus.io v0.22.2/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw= -go.opentelemetry.io/otel v1.7.0 h1:Z2lA3Tdch0iDcrhJXDIlC94XE+bxok1F9B+4Lz/lGsM= -go.opentelemetry.io/otel v1.7.0/go.mod h1:5BdUoMIz5WEs0vt0CUEMtSSaTSHBBVwrhnz7+nrD5xk= -go.opentelemetry.io/otel/sdk v1.7.0 h1:4OmStpcKVOfvDOgCt7UriAPtKolwIhxpnSNI/yK+1B0= -go.opentelemetry.io/otel/sdk v1.7.0/go.mod h1:uTEOTwaqIVuTGiJN7ii13Ibp75wJmYUDe374q6cZwUU= -go.opentelemetry.io/otel/trace v1.7.0 h1:O37Iogk1lEkMRXewVtZ1BBTVn5JEp8GrJvP92bJqC6o= -go.opentelemetry.io/otel/trace v1.7.0/go.mod h1:fzLSB9nqR2eXzxPXb2JW9IKE+ScyXA48yyE4TNvoHqU= +go.opentelemetry.io/otel v1.2.0 h1:YOQDvxO1FayUcT9MIhJhgMyNO1WqoduiyvQHzGN0kUQ= +go.opentelemetry.io/otel v1.2.0/go.mod h1:aT17Fk0Z1Nor9e0uisf98LrntPGMnk4frBO9+dkf69I= +go.opentelemetry.io/otel/sdk v1.2.0 h1:wKN260u4DesJYhyjxDa7LRFkuhH7ncEVKU37LWcyNIo= +go.opentelemetry.io/otel/sdk v1.2.0/go.mod h1:jNN8QtpvbsKhgaC6V5lHiejMoKD+V8uadoSafgHPx1U= +go.opentelemetry.io/otel/trace v1.2.0 h1:Ys3iqbqZhcf28hHzrm5WAquMkDHNZTUkw7KHbuNjej0= +go.opentelemetry.io/otel/trace v1.2.0/go.mod h1:N5FLswTubnxKxOJHM7XZC074qpeEdLy3CgAVsdMucK0= go.uber.org/atomic v1.3.2/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.6.0 h1:Ezj3JGmsOnG1MoRWQkPBsKLe9DwWD9QeXzTRzzldNVk= diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go index cdb4a8b06..cc743bdc4 100644 --- a/trace/opentelemetry/opentelemetry_test.go +++ b/trace/opentelemetry/opentelemetry_test.go @@ -28,7 +28,7 @@ import ( "go.opentelemetry.io/otel/codes" "go.opentelemetry.io/otel/sdk/resource" sdktrace "go.opentelemetry.io/otel/sdk/trace" - semconv "go.opentelemetry.io/otel/semconv/v1.10.0" + semconv "go.opentelemetry.io/otel/semconv/v1.7.0" "gotest.tools/assert" "gotest.tools/assert/cmp" ) From 1958686b4ac321fc46eab5fe2388a0fa1d8d488b Mon Sep 17 00:00:00 2001 From: yabuchan Date: Mon, 4 Jul 2022 21:38:38 +0900 Subject: [PATCH 5/7] remove unnecessary lines --- go.mod | 8 -------- 1 file changed, 8 deletions(-) diff --git a/go.mod b/go.mod index 114ed18e9..66b653ff5 100644 --- a/go.mod +++ b/go.mod @@ -35,11 +35,3 @@ require ( k8s.io/utils v0.0.0-20200912215256-4140de9c8800 sigs.k8s.io/controller-runtime v0.7.1 ) - -replace ( - // Note: Latest opentelemetry (v1.7.0) requires go-logr/logr v1.2 which conflicts with k8s.io/apimachinery. - // Safe to bump up to opentelemetry (v1.7.0) by removing these lines once k8s.io/apimachinery is updated. - go.opentelemetry.io/otel => go.opentelemetry.io/otel v1.2.0 - go.opentelemetry.io/otel/sdk => go.opentelemetry.io/otel/sdk v1.2.0 - go.opentelemetry.io/otel/trace => go.opentelemetry.io/otel/trace v1.2.0 -) From 95bdbdec0de7dbd55fa7ef85e4f5cca9549eb198 Mon Sep 17 00:00:00 2001 From: yabuchan Date: Fri, 8 Jul 2022 00:18:58 +0900 Subject: [PATCH 6/7] reflect review comments --- trace/opentelemetry/opentelemetry.go | 14 ++-- trace/opentelemetry/opentelemetry_test.go | 86 +++++++++++++++-------- 2 files changed, 61 insertions(+), 39 deletions(-) diff --git a/trace/opentelemetry/opentelemetry.go b/trace/opentelemetry/opentelemetry.go index dd50cee01..4bb911e3d 100644 --- a/trace/opentelemetry/opentelemetry.go +++ b/trace/opentelemetry/opentelemetry.go @@ -21,12 +21,13 @@ //`otel.SetTracerProvider(*sdktrace.TracerProvider)`. Examples of customize are setting service name, // use your own exporter (e.g. jaeger, otlp, prometheus, zipkin, and stdout) etc. Do not forget // to call TracerProvider.Shutdown() when you create your TracerProvider to avoid memory leak. -package openTelemetry +package opentelemetry import ( "context" "fmt" "sync" + "time" "go.opentelemetry.io/otel/codes" @@ -184,10 +185,7 @@ func (l *logger) logEvent(ll logLevel, args ...interface{}) { if !l.s.IsRecording() { return } - - //TODO Add log event to span once it is available. - // The Logs signal is not supported in opentelemetry-go yet. - // ref: https://github.com/open-telemetry/opentelemetry-go + l.s.AddEvent(msg, ot.WithTimestamp(time.Now())) } func (l *logger) logEventf(ll logLevel, f string, args ...interface{}) { @@ -207,10 +205,8 @@ func (l *logger) logEventf(ll logLevel, f string, args ...interface{}) { if !l.s.IsRecording() { return } - - //TODO Add log event to span once it is available. - // The Logs signal is not supported in opentelemetry-go yet. - // ref: https://github.com/open-telemetry/opentelemetry-go + msg := fmt.Sprintf(f, args...) + l.s.AddEvent(msg, ot.WithTimestamp(time.Now())) } func (l *logger) WithError(err error) log.Logger { diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go index cc743bdc4..6f75b5ff4 100644 --- a/trace/opentelemetry/opentelemetry_test.go +++ b/trace/opentelemetry/opentelemetry_test.go @@ -12,7 +12,7 @@ // See the License for the specific language governing permissions and // limitations under the License. -package openTelemetry +package opentelemetry import ( "context" @@ -200,6 +200,7 @@ func TestLog(t *testing.T) { logLevel logLevel fields log.Fields msg string + expectedEvents []sdktrace.Event expectedAttributes []attribute.KeyValue }{ { @@ -208,6 +209,7 @@ func TestLog(t *testing.T) { logLevel: lDebug, fields: log.Fields{"testKey1": "value1"}, msg: "message", + expectedEvents: []sdktrace.Event{{Name: "message"}}, expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, }, { description: "info", @@ -215,6 +217,7 @@ func TestLog(t *testing.T) { logLevel: lInfo, fields: log.Fields{"testKey1": "value1"}, msg: "message", + expectedEvents: []sdktrace.Event{{Name: "message"}}, expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, }, { description: "warn", @@ -222,6 +225,7 @@ func TestLog(t *testing.T) { logLevel: lWarn, fields: log.Fields{"testKey1": "value1"}, msg: "message", + expectedEvents: []sdktrace.Event{{Name: "message"}}, expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, }, { description: "error", @@ -229,6 +233,7 @@ func TestLog(t *testing.T) { logLevel: lErr, fields: log.Fields{"testKey1": "value1"}, msg: "message", + expectedEvents: []sdktrace.Event{{Name: "message"}}, expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, }, { description: "fatal", @@ -236,13 +241,14 @@ func TestLog(t *testing.T) { logLevel: lFatal, fields: log.Fields{"testKey1": "value1"}, msg: "message", + expectedEvents: []sdktrace.Event{{Name: "message"}}, expectedAttributes: []attribute.KeyValue{{Key: "testKey1", Value: attribute.StringValue("value1")}}, }, } for _, tt := range testCases { t.Run(tt.description, func(t *testing.T) { - tearDown, p, _ := setupSuite() + tearDown, p, e := setupSuite() defer tearDown(p) ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) @@ -265,7 +271,12 @@ func TestLog(t *testing.T) { } s.End() - //TODO add assertion with exporter here once logic for recoding log event is added. + assert.Assert(t, len(e.events) == len(tt.expectedEvents)) + for i, event := range tt.expectedEvents { + assert.Assert(t, e.events[i].Name == event.Name) + assert.Assert(t, !e.events[i].Time.IsZero()) + } + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { cmp.Contains(fl.a, a) @@ -282,14 +293,17 @@ func TestLogf(t *testing.T) { msg string fields log.Fields args []interface{} + expectedEvents []sdktrace.Event expectedAttributes []attribute.KeyValue }{ { - description: "debug", - spanName: "test", - logLevel: lDebug, - msg: "k1: %s, k2: %v, k3: %d, k4: %v", - fields: map[string]interface{}{"k1": "test", "k2": []string{"test"}, "k3": 1, "k4": []int{1}}, + description: "debug", + spanName: "test", + logLevel: lDebug, + msg: "k1: %s, k2: %v, k3: %d, k4: %v", + fields: map[string]interface{}{"k1": "test", "k2": []string{"test"}, "k3": 1, "k4": []int{1}}, + args: []interface{}{"test", []string{"test"}, int(1), []int{1}}, + expectedEvents: []sdktrace.Event{{Name: "k1: test, k2: [test], k3: 1, k4: [1]"}}, expectedAttributes: []attribute.KeyValue{ attribute.String("k1", "test"), attribute.StringSlice("k2", []string{"test"}), @@ -297,11 +311,13 @@ func TestLogf(t *testing.T) { attribute.IntSlice("k4", []int{1}), }, }, { - description: "info", - spanName: "test", - logLevel: lInfo, - msg: "k1: %d, k2: %v, k3: %f, k4: %v", - fields: map[string]interface{}{"k1": int64(3), "k2": []int64{4}, "k3": float64(2), "k4": []float64{4}}, + description: "info", + spanName: "test", + logLevel: lInfo, + msg: "k1: %d, k2: %v, k3: %f, k4: %v", + fields: map[string]interface{}{"k1": int64(3), "k2": []int64{4}, "k3": float64(2), "k4": []float64{4}}, + args: []interface{}{int64(3), []int64{4}, float64(2), []float64{4}}, + expectedEvents: []sdktrace.Event{{Name: "k1: 3, k2: [4], k3: 2.000000, k4: [4]"}}, expectedAttributes: []attribute.KeyValue{ attribute.Int64("k1", 1), attribute.Int64Slice("k2", []int64{2}), @@ -309,21 +325,25 @@ func TestLogf(t *testing.T) { attribute.Float64Slice("k2", []float64{4}), }, }, { - description: "warn", - spanName: "test", - logLevel: lWarn, - msg: "k1: %v, k2: %v", - fields: map[string]interface{}{"k1": map[int]int{1: 1}, "k2": num(1)}, + description: "warn", + spanName: "test", + logLevel: lWarn, + msg: "k1: %v, k2: %v", + fields: map[string]interface{}{"k1": map[int]int{1: 1}, "k2": num(1)}, + args: []interface{}{map[int]int{1: 1}, num(1)}, + expectedEvents: []sdktrace.Event{{Name: "k1: map[1:1], k2: 1"}}, expectedAttributes: []attribute.KeyValue{ attribute.String("k1", "{1:1}"), attribute.Stringer("k2", num(1)), }, }, { - description: "error", - spanName: "test", - logLevel: lErr, - msg: "k1: %t, k2: %v", - fields: map[string]interface{}{"k1": true, "k2": []bool{true}, "k3": errors.New("fake")}, + description: "error", + spanName: "test", + logLevel: lErr, + msg: "k1: %t, k2: %v, k3: %s", + fields: map[string]interface{}{"k1": true, "k2": []bool{true}, "k3": errors.New("fake")}, + args: []interface{}{true, []bool{true}, errors.New("fake")}, + expectedEvents: []sdktrace.Event{{Name: "k1: true, k2: [true], k3: fake"}}, expectedAttributes: []attribute.KeyValue{ attribute.Bool("k1", true), attribute.BoolSlice("k2", []bool{true}), @@ -333,13 +353,14 @@ func TestLogf(t *testing.T) { description: "fatal", spanName: "test", logLevel: lFatal, + expectedEvents: []sdktrace.Event{{Name: ""}}, expectedAttributes: []attribute.KeyValue{}, }, } for _, tt := range testCases { t.Run(tt.description, func(t *testing.T) { - tearDown, p, _ := setupSuite() + tearDown, p, e := setupSuite() defer tearDown(p) ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) @@ -350,19 +371,24 @@ func TestLogf(t *testing.T) { l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} switch tt.logLevel { case lDebug: - l.WithFields(tt.fields).Debugf(tt.msg, tt.args) + l.WithFields(tt.fields).Debugf(tt.msg, tt.args...) case lInfo: - l.WithFields(tt.fields).Infof(tt.msg, tt.args) + l.WithFields(tt.fields).Infof(tt.msg, tt.args...) case lWarn: - l.WithFields(tt.fields).Warnf(tt.msg, tt.args) + l.WithFields(tt.fields).Warnf(tt.msg, tt.args...) case lErr: - l.WithFields(tt.fields).Errorf(tt.msg, tt.args) + l.WithFields(tt.fields).Errorf(tt.msg, tt.args...) case lFatal: - l.WithFields(tt.fields).Fatalf(tt.msg, tt.args) + l.WithFields(tt.fields).Fatalf(tt.msg, tt.args...) } s.End() - //TODO add assertion with exporter here once logic for recoding log event is added. + assert.Assert(t, len(e.events) == len(tt.expectedEvents)) + for i, event := range tt.expectedEvents { + assert.Assert(t, e.events[i].Name == event.Name, e.events[i].Name) + assert.Assert(t, !e.events[i].Time.IsZero()) + } + assert.Assert(t, len(fl.a) == len(tt.expectedAttributes)) for _, a := range tt.expectedAttributes { cmp.Contains(fl.a, a) From 38e662129d99c06d9ba85455b2145ebbc24f6d7f Mon Sep 17 00:00:00 2001 From: yabuchan Date: Fri, 8 Jul 2022 10:23:17 +0900 Subject: [PATCH 7/7] remove warning from golinter --- trace/opentelemetry/opentelemetry.go | 8 ++------ trace/opentelemetry/opentelemetry_test.go | 14 +++++++------- 2 files changed, 9 insertions(+), 13 deletions(-) diff --git a/trace/opentelemetry/opentelemetry.go b/trace/opentelemetry/opentelemetry.go index 4bb911e3d..f8a8e1c49 100644 --- a/trace/opentelemetry/opentelemetry.go +++ b/trace/opentelemetry/opentelemetry.go @@ -12,13 +12,13 @@ // See the License for the specific language governing permissions and // limitations under the License. -// Package openTelemetry implements a github.com/virtual-kubelet/virtual-kubelet/trace.Tracer +// Package opentelemetry implements a github.com/virtual-kubelet/virtual-kubelet/trace.Tracer // using openTelemetry as a backend. // // Use this by setting `trace.T = Adapter{}` // // For customizing trace provider used in Adapter, set trace provider by -//`otel.SetTracerProvider(*sdktrace.TracerProvider)`. Examples of customize are setting service name, +// `otel.SetTracerProvider(*sdktrace.TracerProvider)`. Examples of customize are setting service name, // use your own exporter (e.g. jaeger, otlp, prometheus, zipkin, and stdout) etc. Do not forget // to call TracerProvider.Shutdown() when you create your TracerProvider to avoid memory leak. package opentelemetry @@ -48,10 +48,6 @@ const ( lFatal logLevel = "FATAL" ) -func (l logLevel) string() string { - return string(l) -} - // Adapter implements the trace.Tracer interface for openTelemetry type Adapter struct{} diff --git a/trace/opentelemetry/opentelemetry_test.go b/trace/opentelemetry/opentelemetry_test.go index 6f75b5ff4..452025798 100644 --- a/trace/opentelemetry/opentelemetry_test.go +++ b/trace/opentelemetry/opentelemetry_test.go @@ -42,7 +42,7 @@ func TestStartSpan(t *testing.T) { defer cancel() a := Adapter{} - ctx, s := a.StartSpan(ctx, "name") + _, s := a.StartSpan(ctx, "name") s.End() }) } @@ -182,7 +182,7 @@ func TestWithFields(t *testing.T) { l := log.G(ctx).WithField("method", tt.spanName) s := &span{s: ots, l: l} - ctx = s.WithFields(ctx, tt.fields) + _ = s.WithFields(ctx, tt.fields) s.End() assert.Assert(t, len(e.attributes) == len(tt.expectedAttributes)) @@ -254,7 +254,7 @@ func TestLog(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() - ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + _, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) fl := &fakeLogger{} l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} switch tt.logLevel { @@ -366,7 +366,7 @@ func TestLogf(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() - ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + _, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) fl := &fakeLogger{} l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} switch tt.logLevel { @@ -437,7 +437,7 @@ func TestLogWithField(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() - ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + _, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) fl := &fakeLogger{} l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} @@ -485,7 +485,7 @@ func TestLogWithError(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() - ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + _, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) fl := &fakeLogger{} l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)} @@ -528,7 +528,7 @@ func TestLogWithFields(t *testing.T) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() - ctx, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) + _, s := otel.Tracer(tt.spanName).Start(ctx, tt.spanName) fl := &fakeLogger{} l := logger{s: s, l: fl, a: make([]attribute.KeyValue, 0)}