From 8ca3874b382735710544fc41c57c679f1f180417 Mon Sep 17 00:00:00 2001 From: Tom Wilkie Date: Fri, 28 Sep 2018 12:49:17 +0100 Subject: [PATCH 01/13] Instrument test exporter for OpenTracing. Also: - Move SpanLogger out of chunk package and reuse it. - Update the logging in the test-exporter to use gokit. Signed-off-by: Tom Wilkie --- pkg/util/spanlogger/spanlogger.go | 40 +++++++++++++++++++++++++++++++ 1 file changed, 40 insertions(+) create mode 100644 pkg/util/spanlogger/spanlogger.go diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go new file mode 100644 index 000000000..86aaddc80 --- /dev/null +++ b/pkg/util/spanlogger/spanlogger.go @@ -0,0 +1,40 @@ +package spanlogger + +import ( + "context" + + "github.com/go-kit/kit/log" + opentracing "github.com/opentracing/opentracing-go" + otlog "github.com/opentracing/opentracing-go/log" + + "github.com/cortexproject/cortex/pkg/util" +) + +// SpanLogger unifies tracing and logging, to reduce repetition. +type SpanLogger struct { + log.Logger + opentracing.Span +} + +// New makes a new SpanLogger. +func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, context.Context) { + span, ctx := opentracing.StartSpanFromContext(ctx, method) + logger := &SpanLogger{ + Logger: log.With(util.WithContext(ctx, util.Logger), "method", method), + Span: span, + } + if len(kvps) > 0 { + logger.Log(kvps...) + } + return logger, ctx +} + +func (s *SpanLogger) Log(kvps ...interface{}) error { + s.Logger.Log(kvps...) + fields, err := otlog.InterleavedKVToFields(kvps...) + if err != nil { + return err + } + s.Span.LogFields(fields...) + return nil +} From 8fbd2395d14b9af7c4db45f1fc4c3c9f5b2432f4 Mon Sep 17 00:00:00 2001 From: Tom Wilkie Date: Sat, 29 Sep 2018 14:06:24 +0100 Subject: [PATCH 02/13] Add comment to appease linter. Signed-off-by: Tom Wilkie --- pkg/util/spanlogger/spanlogger.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 86aaddc80..87d5108b2 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -29,6 +29,8 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, return logger, ctx } +// Log implements gokit's Logger interface; sends logs to underlying logger and +// also puts the on the spans. func (s *SpanLogger) Log(kvps ...interface{}) error { s.Logger.Log(kvps...) fields, err := otlog.InterleavedKVToFields(kvps...) From dbd116ffcf2f3e4f109ac224ad332860702c042d Mon Sep 17 00:00:00 2001 From: Bryan Boreham Date: Wed, 17 Oct 2018 14:29:45 +0100 Subject: [PATCH 03/13] Log opening of span at debug level (#1075) Signed-off-by: Bryan Boreham --- pkg/util/spanlogger/spanlogger.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 87d5108b2..12326db9b 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -4,6 +4,7 @@ import ( "context" "github.com/go-kit/kit/log" + "github.com/go-kit/kit/log/level" opentracing "github.com/opentracing/opentracing-go" otlog "github.com/opentracing/opentracing-go/log" @@ -24,7 +25,7 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, Span: span, } if len(kvps) > 0 { - logger.Log(kvps...) + level.Debug(logger).Log(kvps...) } return logger, ctx } From fd20ed9e2484a7ea4f7ec8636c05254b8bada734 Mon Sep 17 00:00:00 2001 From: Bryan Boreham Date: Wed, 27 Mar 2019 14:33:12 +0000 Subject: [PATCH 04/13] Add SpanLogger.Error method Signed-off-by: Bryan Boreham --- pkg/util/spanlogger/spanlogger.go | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 12326db9b..61d825f8a 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -6,6 +6,7 @@ import ( "github.com/go-kit/kit/log" "github.com/go-kit/kit/log/level" opentracing "github.com/opentracing/opentracing-go" + "github.com/opentracing/opentracing-go/ext" otlog "github.com/opentracing/opentracing-go/log" "github.com/cortexproject/cortex/pkg/util" @@ -41,3 +42,13 @@ func (s *SpanLogger) Log(kvps ...interface{}) error { s.Span.LogFields(fields...) return nil } + +// Error sets error flag and logs the error, if non-nil. Returns the err passed in. +func (s *SpanLogger) Error(err error) error { + if err == nil { + return nil + } + ext.Error.Set(s.Span, true) + s.Span.LogFields(otlog.Error(err)) + return err +} From a10c21b82c535b430c7c91e4cea282fa39d75ffd Mon Sep 17 00:00:00 2001 From: Cyril Tovena Date: Fri, 7 Feb 2020 14:23:07 -0500 Subject: [PATCH 05/13] Adds FromContext to spanlogger package. (#2089) * Adds FromContext to spanlogger package. Signed-off-by: Cyril Tovena * Removes noop spanlogger for clarity/ Signed-off-by: Cyril Tovena * Add missing comment on exported function. Signed-off-by: Cyril Tovena --- pkg/util/spanlogger/noop.go | 52 ++++++++++++++++++++++++++ pkg/util/spanlogger/spanlogger.go | 16 ++++++++ pkg/util/spanlogger/spanlogger_test.go | 21 +++++++++++ 3 files changed, 89 insertions(+) create mode 100644 pkg/util/spanlogger/noop.go create mode 100644 pkg/util/spanlogger/spanlogger_test.go diff --git a/pkg/util/spanlogger/noop.go b/pkg/util/spanlogger/noop.go new file mode 100644 index 000000000..8c7480ec8 --- /dev/null +++ b/pkg/util/spanlogger/noop.go @@ -0,0 +1,52 @@ +package spanlogger + +import ( + opentracing "github.com/opentracing/opentracing-go" + "github.com/opentracing/opentracing-go/log" +) + +type noopTracer struct{} + +type noopSpan struct{} +type noopSpanContext struct{} + +var ( + defaultNoopSpanContext = noopSpanContext{} + defaultNoopSpan = noopSpan{} + defaultNoopTracer = noopTracer{} +) + +const ( + emptyString = "" +) + +func (n noopSpanContext) ForeachBaggageItem(handler func(k, v string) bool) {} + +func (n noopSpan) Context() opentracing.SpanContext { return defaultNoopSpanContext } +func (n noopSpan) SetBaggageItem(key, val string) opentracing.Span { return defaultNoopSpan } +func (n noopSpan) BaggageItem(key string) string { return emptyString } +func (n noopSpan) SetTag(key string, value interface{}) opentracing.Span { return n } +func (n noopSpan) LogFields(fields ...log.Field) {} +func (n noopSpan) LogKV(keyVals ...interface{}) {} +func (n noopSpan) Finish() {} +func (n noopSpan) FinishWithOptions(opts opentracing.FinishOptions) {} +func (n noopSpan) SetOperationName(operationName string) opentracing.Span { return n } +func (n noopSpan) Tracer() opentracing.Tracer { return defaultNoopTracer } +func (n noopSpan) LogEvent(event string) {} +func (n noopSpan) LogEventWithPayload(event string, payload interface{}) {} +func (n noopSpan) Log(data opentracing.LogData) {} + +// StartSpan belongs to the Tracer interface. +func (n noopTracer) StartSpan(operationName string, opts ...opentracing.StartSpanOption) opentracing.Span { + return defaultNoopSpan +} + +// Inject belongs to the Tracer interface. +func (n noopTracer) Inject(sp opentracing.SpanContext, format interface{}, carrier interface{}) error { + return nil +} + +// Extract belongs to the Tracer interface. +func (n noopTracer) Extract(format interface{}, carrier interface{}) (opentracing.SpanContext, error) { + return nil, opentracing.ErrSpanContextNotFound +} diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 61d825f8a..da4037890 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -31,6 +31,22 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, return logger, ctx } +// FromContext returns a span logger using the current parent span. +// If there is no parent span, the Spanlogger will only log to stdout. +func FromContext(ctx context.Context) *SpanLogger { + sp := opentracing.SpanFromContext(ctx) + if sp == nil { + return &SpanLogger{ + Logger: util.Logger, + Span: defaultNoopSpan, + } + } + return &SpanLogger{ + Logger: util.Logger, + Span: sp, + } +} + // Log implements gokit's Logger interface; sends logs to underlying logger and // also puts the on the spans. func (s *SpanLogger) Log(kvps ...interface{}) error { diff --git a/pkg/util/spanlogger/spanlogger_test.go b/pkg/util/spanlogger/spanlogger_test.go new file mode 100644 index 000000000..67fc0748e --- /dev/null +++ b/pkg/util/spanlogger/spanlogger_test.go @@ -0,0 +1,21 @@ +package spanlogger + +import ( + "context" + "testing" + + "github.com/pkg/errors" + "github.com/stretchr/testify/require" +) + +func TestSpanLogger_Log(t *testing.T) { + span, ctx := New(context.Background(), "test", "bar") + _ = span.Log("foo") + newSpan := FromContext(ctx) + require.Equal(t, span.Span, newSpan.Span) + _ = newSpan.Log("bar") + noSpan := FromContext(context.Background()) + _ = noSpan.Log("foo") + require.Error(t, noSpan.Error(errors.New("err"))) + require.NoError(t, noSpan.Error(nil)) +} From a4c75488e80b12c1eeaa4cf191d12b5327ef2ac1 Mon Sep 17 00:00:00 2001 From: Cyril Tovena Date: Fri, 24 Apr 2020 03:44:46 -0400 Subject: [PATCH 06/13] Fix logger context when creating a spanLogger from context. (#2519) * Fix logger context when creating a spanLogger from context. Signed-off-by: Cyril Tovena * Syntax error. Signed-off-by: Cyril Tovena --- pkg/util/spanlogger/spanlogger.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index da4037890..a3018b0f3 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -37,12 +37,12 @@ func FromContext(ctx context.Context) *SpanLogger { sp := opentracing.SpanFromContext(ctx) if sp == nil { return &SpanLogger{ - Logger: util.Logger, + Logger: util.WithContext(ctx, util.Logger), Span: defaultNoopSpan, } } return &SpanLogger{ - Logger: util.Logger, + Logger: util.WithContext(ctx, util.Logger), Span: sp, } } From 02b6bf0620be3adf790bef3699081941a2464096 Mon Sep 17 00:00:00 2001 From: Callum Styan Date: Wed, 12 Aug 2020 07:08:30 -0700 Subject: [PATCH 07/13] Be consistent with span logging, set error=true and use otlog.Error (#2970) * Make use of spanlogger when functions that generate spans result in an error, this is so we consistently have the error=true tag set. Signed-off-by: Callum Styan * Add spanlogger Error to errcheck exclude Signed-off-by: Callum Styan * Review cleanup. Signed-off-by: Callum Styan * Address more review feedback. Signed-off-by: Callum Styan * We need nolint comments on these lines if we want to assign the ctx in attempt to avoid use of the incorrect ctx in the future. Signed-off-by: Callum Styan * Globally exclude SpanLogger.Error() errcheck Signed-off-by: Marco Pracucci Co-authored-by: Marco Pracucci --- pkg/util/spanlogger/spanlogger.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index a3018b0f3..b376d2585 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -59,7 +59,7 @@ func (s *SpanLogger) Log(kvps ...interface{}) error { return nil } -// Error sets error flag and logs the error, if non-nil. Returns the err passed in. +// Error sets error flag and logs the error on the span, if non-nil. Returns the err passed in. func (s *SpanLogger) Error(err error) error { if err == nil { return nil From 6bd75e83378e4c1881cf3f88e853ac6e3efd5466 Mon Sep 17 00:00:00 2001 From: Marco Pracucci Date: Wed, 4 Nov 2020 08:47:01 +0100 Subject: [PATCH 08/13] Added -querier.max-query-lookback and fixed -querier.max-query-into-future (#3452) * Added querier max-query-lookback and fixed max-query-into-future Signed-off-by: Marco Pracucci * Updated PR number Signed-off-by: Marco Pracucci * Fixed tests Signed-off-by: Marco Pracucci * Removed dead code Signed-off-by: Marco Pracucci * Added warning for the deprecated flag Signed-off-by: Marco Pracucci * Addressed review comments Signed-off-by: Marco Pracucci --- pkg/util/spanlogger/spanlogger.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index b376d2585..87a11baaf 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -32,7 +32,7 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, } // FromContext returns a span logger using the current parent span. -// If there is no parent span, the Spanlogger will only log to stdout. +// If there is no parent span, the Spanlogger will only log to global logger. func FromContext(ctx context.Context) *SpanLogger { sp := opentracing.SpanFromContext(ctx) if sp == nil { From 7925a99040805b8a1dc5269f3255935bc11e5dfe Mon Sep 17 00:00:00 2001 From: Robert Fratto Date: Thu, 12 Nov 2020 03:06:22 -0500 Subject: [PATCH 09/13] Support custom log.Logger instances in spanlogger (#3480) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * support custom log.Logger instances in spanlogger Signed-off-by: Robert Fratto * Update pkg/util/spanlogger/spanlogger.go Co-authored-by: Peter Štibraný Signed-off-by: Robert Fratto * add test, fix bug Signed-off-by: Robert Fratto * ignore errors from logging to test spanlogger Signed-off-by: Robert Fratto Co-authored-by: Peter Štibraný --- pkg/util/spanlogger/spanlogger.go | 44 ++++++++++++++++++++------ pkg/util/spanlogger/spanlogger_test.go | 30 ++++++++++++++++++ 2 files changed, 65 insertions(+), 9 deletions(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 87a11baaf..056e59ae2 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -12,37 +12,63 @@ import ( "github.com/cortexproject/cortex/pkg/util" ) +type loggerCtxMarker struct{} + +var ( + loggerCtxKey = &loggerCtxMarker{} +) + // SpanLogger unifies tracing and logging, to reduce repetition. type SpanLogger struct { log.Logger opentracing.Span } -// New makes a new SpanLogger. +// New makes a new SpanLogger, where logs will be sent to the global logger. func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, context.Context) { + return NewWithLogger(ctx, util.Logger, method, kvps...) +} + +// NewWithLogger makes a new SpanLogger with a custom log.Logger to send logs +// to. The provided context will have the logger attached to it and can be +// retrieved with FromContext or FromContextWithFallback. +func NewWithLogger(ctx context.Context, l log.Logger, method string, kvps ...interface{}) (*SpanLogger, context.Context) { span, ctx := opentracing.StartSpanFromContext(ctx, method) logger := &SpanLogger{ - Logger: log.With(util.WithContext(ctx, util.Logger), "method", method), + Logger: log.With(util.WithContext(ctx, l), "method", method), Span: span, } if len(kvps) > 0 { level.Debug(logger).Log(kvps...) } + + ctx = context.WithValue(ctx, loggerCtxKey, l) return logger, ctx } -// FromContext returns a span logger using the current parent span. -// If there is no parent span, the Spanlogger will only log to global logger. +// FromContext returns a span logger using the current parent span. If there +// is no parent span, the SpanLogger will only log to the logger +// in the context. If the context doesn't have a logger, the global logger +// is used. func FromContext(ctx context.Context) *SpanLogger { + return FromContextWithFallback(ctx, util.Logger) +} + +// FromContextWithFallback returns a span logger using the current parent span. +// IF there is no parent span, the SpanLogger will only log to the logger +// within the context. If the context doesn't have a logger, the fallback +// logger is used. +func FromContextWithFallback(ctx context.Context, fallback log.Logger) *SpanLogger { + logger, ok := ctx.Value(loggerCtxKey).(log.Logger) + if !ok { + logger = fallback + } sp := opentracing.SpanFromContext(ctx) if sp == nil { - return &SpanLogger{ - Logger: util.WithContext(ctx, util.Logger), - Span: defaultNoopSpan, - } + sp = defaultNoopSpan } return &SpanLogger{ - Logger: util.WithContext(ctx, util.Logger), + Logger: util.WithContext(ctx, logger), Span: sp, } } diff --git a/pkg/util/spanlogger/spanlogger_test.go b/pkg/util/spanlogger/spanlogger_test.go index 67fc0748e..fbea0cb26 100644 --- a/pkg/util/spanlogger/spanlogger_test.go +++ b/pkg/util/spanlogger/spanlogger_test.go @@ -4,6 +4,7 @@ import ( "context" "testing" + "github.com/go-kit/kit/log" "github.com/pkg/errors" "github.com/stretchr/testify/require" ) @@ -19,3 +20,32 @@ func TestSpanLogger_Log(t *testing.T) { require.Error(t, noSpan.Error(errors.New("err"))) require.NoError(t, noSpan.Error(nil)) } + +func TestSpanLogger_CustomLogger(t *testing.T) { + var logged [][]interface{} + var logger funcLogger = func(keyvals ...interface{}) error { + logged = append(logged, keyvals) + return nil + } + span, ctx := NewWithLogger(context.Background(), logger, "test") + _ = span.Log("msg", "original spanlogger") + + span = FromContextWithFallback(ctx, log.NewNopLogger()) + _ = span.Log("msg", "restored spanlogger") + + span = FromContextWithFallback(context.Background(), logger) + _ = span.Log("msg", "fallback spanlogger") + + expect := [][]interface{}{ + {"method", "test", "msg", "original spanlogger"}, + {"msg", "restored spanlogger"}, + {"msg", "fallback spanlogger"}, + } + require.Equal(t, expect, logged) +} + +type funcLogger func(keyvals ...interface{}) error + +func (f funcLogger) Log(keyvals ...interface{}) error { + return f(keyvals...) +} From aad88602af24de81c5e81562ab58322e18a3206c Mon Sep 17 00:00:00 2001 From: Kevin Minehart Date: Tue, 26 Jan 2021 11:47:33 -0600 Subject: [PATCH 10/13] Move some utility functions out of `util` and into their own packages (#3734) * separate out some util packages Signed-off-by: Kevin Minehart * use goimports with -local Signed-off-by: Kevin Minehart * refactor: reduce the number of transitive imports when using math and logging functions Signed-off-by: Kevin Minehart * add deprecation warning to pkg/log/log.go Signed-off-by: Kevin Minehart --- pkg/util/spanlogger/spanlogger.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 056e59ae2..4b6131d45 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -9,7 +9,7 @@ import ( "github.com/opentracing/opentracing-go/ext" otlog "github.com/opentracing/opentracing-go/log" - "github.com/cortexproject/cortex/pkg/util" + util_log "github.com/cortexproject/cortex/pkg/util/log" ) type loggerCtxMarker struct{} @@ -26,7 +26,7 @@ type SpanLogger struct { // New makes a new SpanLogger, where logs will be sent to the global logger. func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, context.Context) { - return NewWithLogger(ctx, util.Logger, method, kvps...) + return NewWithLogger(ctx, util_log.Logger, method, kvps...) } // NewWithLogger makes a new SpanLogger with a custom log.Logger to send logs @@ -35,7 +35,7 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, func NewWithLogger(ctx context.Context, l log.Logger, method string, kvps ...interface{}) (*SpanLogger, context.Context) { span, ctx := opentracing.StartSpanFromContext(ctx, method) logger := &SpanLogger{ - Logger: log.With(util.WithContext(ctx, l), "method", method), + Logger: log.With(util_log.WithContext(ctx, l), "method", method), Span: span, } if len(kvps) > 0 { @@ -51,7 +51,7 @@ func NewWithLogger(ctx context.Context, l log.Logger, method string, kvps ...int // in the context. If the context doesn't have a logger, the global logger // is used. func FromContext(ctx context.Context) *SpanLogger { - return FromContextWithFallback(ctx, util.Logger) + return FromContextWithFallback(ctx, util_log.Logger) } // FromContextWithFallback returns a span logger using the current parent span. @@ -68,7 +68,7 @@ func FromContextWithFallback(ctx context.Context, fallback log.Logger) *SpanLogg sp = defaultNoopSpan } return &SpanLogger{ - Logger: util.WithContext(ctx, logger), + Logger: util_log.WithContext(ctx, logger), Span: sp, } } From 93f5cfabdec1a11e266ee17aeb3fbf9276d6e3f9 Mon Sep 17 00:00:00 2001 From: Vladyslav Diachenko <82767850+vlad-diachenko@users.noreply.github.com> Date: Thu, 20 May 2021 22:22:22 +0300 Subject: [PATCH 11/13] #4147 added `tenant_id` tag to tracing spans (#4186) * #4147 1. added logic to add tag `tenant_id` to tracing spans if tenant is defined in context. 2. added additional tracing spans to merge_querier's methods Signed-off-by: Vladyslav Diachenko * #4147 fixed errors reported by linters Signed-off-by: Vladyslav Diachenko * #4147 1.changed value of tenant_id tag in tracing span from string value to array 2. removed import alias for spanlogger Signed-off-by: Vladyslav Diachenko * #4147 1. fixed tests 2. fixed name of the spans in mergeQuerier Signed-off-by: Vladyslav Diachenko * #4147 updated CHANGELOG.md Signed-off-by: Vladyslav Diachenko * #4147 passed method's span context to mergeDistinctStringSlice function to create inner spans under this context Signed-off-by: Vladyslav Diachenko * #4147 added mocktracer package for testing purpose Signed-off-by: Vladyslav Diachenko * #4147 fixed code style and removed redundant context param that is not used in callback function Signed-off-by: Vladyslav Diachenko * #4147 fixed code style Signed-off-by: Vladyslav Diachenko --- pkg/util/spanlogger/spanlogger.go | 8 ++++++++ pkg/util/spanlogger/spanlogger_test.go | 24 ++++++++++++++++++++++++ 2 files changed, 32 insertions(+) diff --git a/pkg/util/spanlogger/spanlogger.go b/pkg/util/spanlogger/spanlogger.go index 4b6131d45..a856ceed7 100644 --- a/pkg/util/spanlogger/spanlogger.go +++ b/pkg/util/spanlogger/spanlogger.go @@ -9,11 +9,16 @@ import ( "github.com/opentracing/opentracing-go/ext" otlog "github.com/opentracing/opentracing-go/log" + "github.com/cortexproject/cortex/pkg/tenant" util_log "github.com/cortexproject/cortex/pkg/util/log" ) type loggerCtxMarker struct{} +const ( + TenantIDTagName = "tenant_ids" +) + var ( loggerCtxKey = &loggerCtxMarker{} ) @@ -34,6 +39,9 @@ func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, // retrieved with FromContext or FromContextWithFallback. func NewWithLogger(ctx context.Context, l log.Logger, method string, kvps ...interface{}) (*SpanLogger, context.Context) { span, ctx := opentracing.StartSpanFromContext(ctx, method) + if ids, _ := tenant.TenantIDs(ctx); len(ids) > 0 { + span.SetTag(TenantIDTagName, ids) + } logger := &SpanLogger{ Logger: log.With(util_log.WithContext(ctx, l), "method", method), Span: span, diff --git a/pkg/util/spanlogger/spanlogger_test.go b/pkg/util/spanlogger/spanlogger_test.go index fbea0cb26..4d701fcbb 100644 --- a/pkg/util/spanlogger/spanlogger_test.go +++ b/pkg/util/spanlogger/spanlogger_test.go @@ -5,8 +5,11 @@ import ( "testing" "github.com/go-kit/kit/log" + "github.com/opentracing/opentracing-go" + "github.com/opentracing/opentracing-go/mocktracer" "github.com/pkg/errors" "github.com/stretchr/testify/require" + "github.com/weaveworks/common/user" ) func TestSpanLogger_Log(t *testing.T) { @@ -44,6 +47,27 @@ func TestSpanLogger_CustomLogger(t *testing.T) { require.Equal(t, expect, logged) } +func TestSpanCreatedWithTenantTag(t *testing.T) { + mockSpan := createSpan(user.InjectOrgID(context.Background(), "team-a")) + + require.Equal(t, []string{"team-a"}, mockSpan.Tag(TenantIDTagName)) +} + +func TestSpanCreatedWithoutTenantTag(t *testing.T) { + mockSpan := createSpan(context.Background()) + + _, exist := mockSpan.Tags()[TenantIDTagName] + require.False(t, exist) +} + +func createSpan(ctx context.Context) *mocktracer.MockSpan { + mockTracer := mocktracer.New() + opentracing.SetGlobalTracer(mockTracer) + + logger, _ := New(ctx, "name") + return logger.Span.(*mocktracer.MockSpan) +} + type funcLogger func(keyvals ...interface{}) error func (f funcLogger) Log(keyvals ...interface{}) error { From 4062d1d213fdd74345e661a2ca4f78574aa3eb77 Mon Sep 17 00:00:00 2001 From: Arve Knudsen Date: Thu, 7 Oct 2021 19:00:29 +0200 Subject: [PATCH 12/13] Move pkg/util/spanlogger to root Signed-off-by: Arve Knudsen --- {pkg/util/spanlogger => spanlogger}/noop.go | 0 {pkg/util/spanlogger => spanlogger}/spanlogger.go | 0 {pkg/util/spanlogger => spanlogger}/spanlogger_test.go | 0 3 files changed, 0 insertions(+), 0 deletions(-) rename {pkg/util/spanlogger => spanlogger}/noop.go (100%) rename {pkg/util/spanlogger => spanlogger}/spanlogger.go (100%) rename {pkg/util/spanlogger => spanlogger}/spanlogger_test.go (100%) diff --git a/pkg/util/spanlogger/noop.go b/spanlogger/noop.go similarity index 100% rename from pkg/util/spanlogger/noop.go rename to spanlogger/noop.go diff --git a/pkg/util/spanlogger/spanlogger.go b/spanlogger/spanlogger.go similarity index 100% rename from pkg/util/spanlogger/spanlogger.go rename to spanlogger/spanlogger.go diff --git a/pkg/util/spanlogger/spanlogger_test.go b/spanlogger/spanlogger_test.go similarity index 100% rename from pkg/util/spanlogger/spanlogger_test.go rename to spanlogger/spanlogger_test.go From fa597b572e845c87adc6832c30cd5c01c76d609e Mon Sep 17 00:00:00 2001 From: Arve Knudsen Date: Thu, 7 Oct 2021 11:25:15 +0200 Subject: [PATCH 13/13] Add spanlogger package Signed-off-by: Arve Knudsen --- CHANGELOG.md | 1 + spanlogger/spanlogger.go | 89 +++++++++++++++++++++-------------- spanlogger/spanlogger_test.go | 21 +++++---- 3 files changed, 66 insertions(+), 45 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1250ce6f3..e8149102a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,3 +12,4 @@ * [ENHANCEMENT] Add limiter package. #41 * [ENHANCEMENT] Add grpcclient, grpcencoding and grpcutil packages. #39 * [ENHANCEMENT] Replace go-kit/kit/log with go-kit/log. #52 +* [ENHANCEMENT] Add spanlogger package. #42 \ No newline at end of file diff --git a/spanlogger/spanlogger.go b/spanlogger/spanlogger.go index a856ceed7..b2a6d2c0e 100644 --- a/spanlogger/spanlogger.go +++ b/spanlogger/spanlogger.go @@ -2,21 +2,22 @@ package spanlogger import ( "context" + "strings" - "github.com/go-kit/kit/log" - "github.com/go-kit/kit/log/level" + "github.com/go-kit/log" + "github.com/go-kit/log/level" opentracing "github.com/opentracing/opentracing-go" "github.com/opentracing/opentracing-go/ext" otlog "github.com/opentracing/opentracing-go/log" - - "github.com/cortexproject/cortex/pkg/tenant" - util_log "github.com/cortexproject/cortex/pkg/util/log" + "github.com/weaveworks/common/tracing" + "github.com/weaveworks/common/user" ) type loggerCtxMarker struct{} const ( - TenantIDTagName = "tenant_ids" + // TenantIDsTagName is the tenant IDs tag name. + TenantIDsTagName = "tenant_ids" ) var ( @@ -29,44 +30,30 @@ type SpanLogger struct { opentracing.Span } -// New makes a new SpanLogger, where logs will be sent to the global logger. -func New(ctx context.Context, method string, kvps ...interface{}) (*SpanLogger, context.Context) { - return NewWithLogger(ctx, util_log.Logger, method, kvps...) -} - -// NewWithLogger makes a new SpanLogger with a custom log.Logger to send logs -// to. The provided context will have the logger attached to it and can be -// retrieved with FromContext or FromContextWithFallback. -func NewWithLogger(ctx context.Context, l log.Logger, method string, kvps ...interface{}) (*SpanLogger, context.Context) { +// New makes a new SpanLogger with a log.Logger to send logs to. The provided context will have the logger attached +// to it and can be retrieved with FromContext. +func New(ctx context.Context, logger log.Logger, method string, kvps ...interface{}) (*SpanLogger, context.Context) { span, ctx := opentracing.StartSpanFromContext(ctx, method) - if ids, _ := tenant.TenantIDs(ctx); len(ids) > 0 { - span.SetTag(TenantIDTagName, ids) + if id := tenantID(ctx); id != "" { + span.SetTag(TenantIDsTagName, []string{id}) } - logger := &SpanLogger{ - Logger: log.With(util_log.WithContext(ctx, l), "method", method), + l := &SpanLogger{ + Logger: log.With(withContext(ctx, logger), "method", method), Span: span, } if len(kvps) > 0 { - level.Debug(logger).Log(kvps...) + level.Debug(l).Log(kvps...) } - ctx = context.WithValue(ctx, loggerCtxKey, l) - return logger, ctx -} - -// FromContext returns a span logger using the current parent span. If there -// is no parent span, the SpanLogger will only log to the logger -// in the context. If the context doesn't have a logger, the global logger -// is used. -func FromContext(ctx context.Context) *SpanLogger { - return FromContextWithFallback(ctx, util_log.Logger) + ctx = context.WithValue(ctx, loggerCtxKey, logger) + return l, ctx } -// FromContextWithFallback returns a span logger using the current parent span. -// IF there is no parent span, the SpanLogger will only log to the logger +// FromContext returns a span logger using the current parent span. +// If there is no parent span, the SpanLogger will only log to the logger // within the context. If the context doesn't have a logger, the fallback // logger is used. -func FromContextWithFallback(ctx context.Context, fallback log.Logger) *SpanLogger { +func FromContext(ctx context.Context, fallback log.Logger) *SpanLogger { logger, ok := ctx.Value(loggerCtxKey).(log.Logger) if !ok { logger = fallback @@ -76,7 +63,7 @@ func FromContextWithFallback(ctx context.Context, fallback log.Logger) *SpanLogg sp = defaultNoopSpan } return &SpanLogger{ - Logger: util_log.WithContext(ctx, logger), + Logger: withContext(ctx, logger), Span: sp, } } @@ -93,7 +80,7 @@ func (s *SpanLogger) Log(kvps ...interface{}) error { return nil } -// Error sets error flag and logs the error on the span, if non-nil. Returns the err passed in. +// Error sets error flag and logs the error on the span, if non-nil. Returns the err passed in. func (s *SpanLogger) Error(err error) error { if err == nil { return nil @@ -102,3 +89,35 @@ func (s *SpanLogger) Error(err error) error { s.Span.LogFields(otlog.Error(err)) return err } + +// tenantID tries to extract the tenant ID from ctx. +func tenantID(ctx context.Context) string { + //lint:ignore faillint wrapper around upstream method + id, err := user.ExtractOrgID(ctx) + if err != nil { + return "" + } + + // handle the relative reference to current and parent path. + if id == "." || id == ".." || strings.ContainsAny(id, `\/`) { + return "" + } + + return id +} + +func withContext(ctx context.Context, l log.Logger) log.Logger { + // Weaveworks uses "orgs" and "orgID" to represent Cortex users, + // even though the code-base generally uses `userID` to refer to the same thing. + userID := tenantID(ctx) + if userID != "" { + l = log.With(l, "org_id", userID) + } + + traceID, ok := tracing.ExtractSampledTraceID(ctx) + if !ok { + return l + } + + return log.With(l, "traceID", traceID) +} diff --git a/spanlogger/spanlogger_test.go b/spanlogger/spanlogger_test.go index 4d701fcbb..1c05d00ad 100644 --- a/spanlogger/spanlogger_test.go +++ b/spanlogger/spanlogger_test.go @@ -4,7 +4,7 @@ import ( "context" "testing" - "github.com/go-kit/kit/log" + "github.com/go-kit/log" "github.com/opentracing/opentracing-go" "github.com/opentracing/opentracing-go/mocktracer" "github.com/pkg/errors" @@ -13,12 +13,13 @@ import ( ) func TestSpanLogger_Log(t *testing.T) { - span, ctx := New(context.Background(), "test", "bar") + logger := log.NewNopLogger() + span, ctx := New(context.Background(), logger, "test", "bar") _ = span.Log("foo") - newSpan := FromContext(ctx) + newSpan := FromContext(ctx, logger) require.Equal(t, span.Span, newSpan.Span) _ = newSpan.Log("bar") - noSpan := FromContext(context.Background()) + noSpan := FromContext(context.Background(), logger) _ = noSpan.Log("foo") require.Error(t, noSpan.Error(errors.New("err"))) require.NoError(t, noSpan.Error(nil)) @@ -30,13 +31,13 @@ func TestSpanLogger_CustomLogger(t *testing.T) { logged = append(logged, keyvals) return nil } - span, ctx := NewWithLogger(context.Background(), logger, "test") + span, ctx := New(context.Background(), logger, "test") _ = span.Log("msg", "original spanlogger") - span = FromContextWithFallback(ctx, log.NewNopLogger()) + span = FromContext(ctx, log.NewNopLogger()) _ = span.Log("msg", "restored spanlogger") - span = FromContextWithFallback(context.Background(), logger) + span = FromContext(context.Background(), logger) _ = span.Log("msg", "fallback spanlogger") expect := [][]interface{}{ @@ -50,13 +51,13 @@ func TestSpanLogger_CustomLogger(t *testing.T) { func TestSpanCreatedWithTenantTag(t *testing.T) { mockSpan := createSpan(user.InjectOrgID(context.Background(), "team-a")) - require.Equal(t, []string{"team-a"}, mockSpan.Tag(TenantIDTagName)) + require.Equal(t, []string{"team-a"}, mockSpan.Tag(TenantIDsTagName)) } func TestSpanCreatedWithoutTenantTag(t *testing.T) { mockSpan := createSpan(context.Background()) - _, exist := mockSpan.Tags()[TenantIDTagName] + _, exist := mockSpan.Tags()[TenantIDsTagName] require.False(t, exist) } @@ -64,7 +65,7 @@ func createSpan(ctx context.Context) *mocktracer.MockSpan { mockTracer := mocktracer.New() opentracing.SetGlobalTracer(mockTracer) - logger, _ := New(ctx, "name") + logger, _ := New(ctx, log.NewNopLogger(), "name") return logger.Span.(*mocktracer.MockSpan) }