From 2a728717a51054d54e4d995e08d0b85e68389570 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Thu, 19 Sep 2024 10:51:39 -0700 Subject: [PATCH] Update `minsev` to allow dynamic severities (#6116) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Similar to [`slog`](https://pkg.go.dev/log/slog#hdr-Levels), allow the `minsev.LogProcessor` to be configured with dynamic severity resolution. --------- Co-authored-by: Robert Pająk --- CHANGELOG.md | 13 +++ processors/minsev/example_test.go | 50 ++++++++++++ processors/minsev/minsev.go | 26 ++++-- processors/minsev/minsev_test.go | 71 ++++++++++++++--- processors/minsev/severity.go | 124 +++++++++++++++++++++++++++++ processors/minsev/severity_test.go | 38 +++++++++ 6 files changed, 304 insertions(+), 18 deletions(-) create mode 100644 processors/minsev/example_test.go create mode 100644 processors/minsev/severity.go create mode 100644 processors/minsev/severity_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 96a9981cc5f..2d863737be0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,10 +8,23 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ## [Unreleased] +### Added + +- The `Severitier` and `SeverityVar` types are added to `go.opentelemetry.io/contrib/processors/minsev` allowing dynamic configuration of the severity used by the `LogProcessor`. (#6116) + +### Changed + +- The function signature of `NewLogProcessor` in `go.opentelemetry.io/contrib/processors/minsev` has changed to accept the added `Severitier` interface instead of a `log.Severity`. (#6116) + ### Fixed - Possible nil dereference panic in `go.opentelemetry.io/contrib/instrumentation/net/http/httptrace/otelhttptrace`. (#5965) +### Removed + +- The `Minimum` field of the `LogProcessor` in `go.opentelemetry.io/contrib/processors/minsev` is removed. + Use `NewLogProcessor` to configure this setting. (#6116) + diff --git a/processors/minsev/example_test.go b/processors/minsev/example_test.go new file mode 100644 index 00000000000..289633c5e87 --- /dev/null +++ b/processors/minsev/example_test.go @@ -0,0 +1,50 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package minsev // import "go.opentelemetry.io/contrib/processors/minsev" + +import ( + "context" + "fmt" + "os" + "strings" + "sync" + + "go.opentelemetry.io/otel/log" +) + +const key = "OTEL_LOG_LEVEL" + +var getSeverity = sync.OnceValue(func() log.Severity { + conv := map[string]log.Severity{ + "": log.SeverityInfo, // Default to SeverityInfo for unset. + "debug": log.SeverityDebug, + "info": log.SeverityInfo, + "warn": log.SeverityWarn, + "error": log.SeverityError, + } + // log.SeverityUndefined for unknown values. + return conv[strings.ToLower(os.Getenv(key))] +}) + +type EnvSeverity struct{} + +func (EnvSeverity) Severity() log.Severity { return getSeverity() } + +func ExampleSeveritier() { + // Mock an environment variable setup that would be done externally. + _ = os.Setenv(key, "error") + + p := NewLogProcessor(&processor{}, EnvSeverity{}) + + ctx, params := context.Background(), log.EnabledParameters{} + params.SetSeverity(log.SeverityDebug) + fmt.Println(p.Enabled(ctx, params)) + + params.SetSeverity(log.SeverityError) + fmt.Println(p.Enabled(ctx, params)) + + // Output: + // false + // true +} diff --git a/processors/minsev/minsev.go b/processors/minsev/minsev.go index fa6229f1d65..e4625359193 100644 --- a/processors/minsev/minsev.go +++ b/processors/minsev/minsev.go @@ -15,13 +15,22 @@ import ( // NewLogProcessor returns a new [LogProcessor] that wraps the downstream // [log.Processor]. // +// severity reports the minimum record severity that will be logged. The +// LogProcessor discards records with lower severities. If severity is nil, +// SeverityInfo is used as a default. The LogProcessor calls severity.Severity +// for each record processed or queried; to adjust the minimum level +// dynamically, use a [SeverityVar]. +// // If downstream is nil a default No-Op [log.Processor] is used. The returned // processor will not be enabled for nor emit any records. -func NewLogProcessor(downstream log.Processor, minimum api.Severity) *LogProcessor { +func NewLogProcessor(downstream log.Processor, severity Severitier) *LogProcessor { if downstream == nil { downstream = defaultProcessor } - p := &LogProcessor{Processor: downstream, Minimum: minimum} + if severity == nil { + severity = SeverityInfo + } + p := &LogProcessor{Processor: downstream, sev: severity} if fp, ok := downstream.(filterProcessor); ok { p.filter = fp } @@ -45,8 +54,8 @@ type filterProcessor interface { type LogProcessor struct { log.Processor - filter filterProcessor - Minimum api.Severity + filter filterProcessor + sev Severitier } // Compile time assertion that LogProcessor implements log.Processor. @@ -56,7 +65,7 @@ var _ log.Processor = (*LogProcessor)(nil) // of record is greater than or equal to p.Minimum. Otherwise, record is // dropped. func (p *LogProcessor) OnEmit(ctx context.Context, record *log.Record) error { - if record.Severity() >= p.Minimum { + if record.Severity() >= p.sev.Severity() { return p.Processor.OnEmit(ctx, record) } return nil @@ -66,15 +75,16 @@ func (p *LogProcessor) OnEmit(ctx context.Context, record *log.Record) error { // severity of param is greater than or equal to p.Minimum. Otherwise false is // returned. func (p *LogProcessor) Enabled(ctx context.Context, param api.EnabledParameters) bool { - lvl, ok := param.Severity() + sev, ok := param.Severity() if !ok { return true } if p.filter != nil { - return lvl >= p.Minimum && p.filter.Enabled(ctx, param) + return sev >= p.sev.Severity() && + p.filter.Enabled(ctx, param) } - return lvl >= p.Minimum + return sev >= p.sev.Severity() } var defaultProcessor = noopProcessor{} diff --git a/processors/minsev/minsev_test.go b/processors/minsev/minsev_test.go index a165e6008cd..3f43af455b1 100644 --- a/processors/minsev/minsev_test.go +++ b/processors/minsev/minsev_test.go @@ -22,6 +22,10 @@ var severities = []api.Severity{ api.SeverityFatal, api.SeverityFatal1, api.SeverityFatal2, api.SeverityFatal3, api.SeverityFatal4, } +type apiSev api.Severity + +func (s apiSev) Severity() api.Severity { return api.Severity(s) } + type emitArgs struct { Ctx context.Context Record *log.Record @@ -68,11 +72,33 @@ func (p *processor) Reset() { p.ForceFlushCalls = p.ForceFlushCalls[:0] } +func TestLogProcessorDynamicSeverity(t *testing.T) { + sev := new(SeverityVar) + wrapped := new(processor) + p := NewLogProcessor(wrapped, sev) + + ctx := context.Background() + params := &api.EnabledParameters{} + params.SetSeverity(api.SeverityDebug) + assert.False(t, p.Enabled(ctx, *params), api.SeverityDebug.String()) + + params.SetSeverity(api.SeverityInfo) + assert.True(t, p.Enabled(ctx, *params), api.SeverityInfo.String()) + + sev.Set(SeverityError) + + params.SetSeverity(api.SeverityInfo) + assert.False(t, p.Enabled(ctx, *params), api.SeverityInfo.String()) + + params.SetSeverity(api.SeverityError) + assert.True(t, p.Enabled(ctx, *params), api.SeverityError.String()) +} + func TestLogProcessorOnEmit(t *testing.T) { t.Run("Passthrough", func(t *testing.T) { wrapped := &processor{ReturnErr: assert.AnError} - p := NewLogProcessor(wrapped, api.SeverityTrace1) + p := NewLogProcessor(wrapped, SeverityTrace1) ctx := context.Background() r := &log.Record{} for _, sev := range severities { @@ -90,12 +116,12 @@ func TestLogProcessorOnEmit(t *testing.T) { t.Run("Dropped", func(t *testing.T) { wrapped := &processor{ReturnErr: assert.AnError} - p := NewLogProcessor(wrapped, api.SeverityFatal4+1) + p := NewLogProcessor(wrapped, apiSev(api.SeverityFatal4+1)) ctx := context.Background() r := &log.Record{} for _, sev := range severities { r.SetSeverity(sev) - assert.NoError(t, p.OnEmit(ctx, r), assert.AnError, sev.String()) + assert.NoError(t, p.OnEmit(ctx, r), sev.String()) if !assert.Lenf(t, wrapped.OnEmitCalls, 0, "Record with severity %s passed-through", sev) { wrapped.Reset() @@ -108,7 +134,7 @@ func TestLogProcessorEnabled(t *testing.T) { t.Run("Passthrough", func(t *testing.T) { wrapped := &processor{} - p := NewLogProcessor(wrapped, api.SeverityTrace1) + p := NewLogProcessor(wrapped, SeverityTrace1) ctx := context.Background() param := api.EnabledParameters{} for _, sev := range severities { @@ -126,7 +152,7 @@ func TestLogProcessorEnabled(t *testing.T) { t.Run("NotEnabled", func(t *testing.T) { wrapped := &processor{} - p := NewLogProcessor(wrapped, api.SeverityFatal4+1) + p := NewLogProcessor(wrapped, apiSev(api.SeverityFatal4+1)) ctx := context.Background() param := api.EnabledParameters{} for _, sev := range severities { @@ -138,12 +164,32 @@ func TestLogProcessorEnabled(t *testing.T) { } } }) + + t.Run("NoFiltered", func(t *testing.T) { + wrapped := &processor{} + + pruned := struct{ log.Processor }{wrapped} // Remove the Enabled method. + p := NewLogProcessor(pruned, SeverityInfo) + ctx := context.Background() + params := &api.EnabledParameters{} + + params.SetSeverity(api.SeverityDebug) + assert.False(t, p.Enabled(ctx, *params)) + + params.SetSeverity(api.SeverityInfo) + assert.True(t, p.Enabled(ctx, *params)) + + params.SetSeverity(api.SeverityError) + assert.True(t, p.Enabled(ctx, *params)) + + assert.Len(t, wrapped.EnabledCalls, 0) + }) } func TestLogProcessorForceFlushPassthrough(t *testing.T) { wrapped := &processor{ReturnErr: assert.AnError} - p := NewLogProcessor(wrapped, api.SeverityTrace1) + p := NewLogProcessor(wrapped, SeverityTrace1) ctx := context.Background() assert.ErrorIs(t, p.ForceFlush(ctx), assert.AnError) assert.Len(t, wrapped.ForceFlushCalls, 1, "ForceFlush not passed-through") @@ -152,14 +198,19 @@ func TestLogProcessorForceFlushPassthrough(t *testing.T) { func TestLogProcessorShutdownPassthrough(t *testing.T) { wrapped := &processor{ReturnErr: assert.AnError} - p := NewLogProcessor(wrapped, api.SeverityTrace1) + p := NewLogProcessor(wrapped, SeverityTrace1) ctx := context.Background() assert.ErrorIs(t, p.Shutdown(ctx), assert.AnError) assert.Len(t, wrapped.ShutdownCalls, 1, "Shutdown not passed-through") } +func TestLogProcessorNilSeverity(t *testing.T) { + p := NewLogProcessor(nil, nil) + assert.Equal(t, SeverityInfo, p.sev.(Severity)) +} + func TestLogProcessorNilDownstream(t *testing.T) { - p := NewLogProcessor(nil, api.SeverityTrace1) + p := NewLogProcessor(nil, SeverityTrace1) ctx := context.Background() r := new(log.Record) r.SetSeverity(api.SeverityTrace1) @@ -200,6 +251,6 @@ func BenchmarkLogProcessor(b *testing.B) { } b.Run("Base", run(defaultProcessor)) - b.Run("Enabled", run(NewLogProcessor(nil, api.SeverityTrace))) - b.Run("Disabled", run(NewLogProcessor(nil, api.SeverityDebug))) + b.Run("Enabled", run(NewLogProcessor(nil, SeverityTrace))) + b.Run("Disabled", run(NewLogProcessor(nil, SeverityDebug))) } diff --git a/processors/minsev/severity.go b/processors/minsev/severity.go new file mode 100644 index 00000000000..d3ef42b922e --- /dev/null +++ b/processors/minsev/severity.go @@ -0,0 +1,124 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package minsev // import "go.opentelemetry.io/contrib/processors/minsev" + +import ( + "sync/atomic" + + "go.opentelemetry.io/otel/log" +) + +// Severity represents a log record severity (also known as log level). Smaller +// numerical values correspond to less severe log records (such as debug +// events), larger numerical values correspond to more severe log records (such +// as errors and critical events). +type Severity int + +// Severity values defined by OpenTelemetry. +const ( + // A fine-grained debugging log record. Typically disabled in default + // configurations. + SeverityTrace1 Severity = -8 // TRACE + SeverityTrace2 Severity = -7 // TRACE2 + SeverityTrace3 Severity = -6 // TRACE3 + SeverityTrace4 Severity = -5 // TRACE4 + + // A debugging log record. + SeverityDebug1 Severity = -4 // DEBUG + SeverityDebug2 Severity = -3 // DEBUG2 + SeverityDebug3 Severity = -2 // DEBUG3 + SeverityDebug4 Severity = -1 // DEBUG4 + + // An informational log record. Indicates that an event happened. + SeverityInfo1 Severity = 0 // INFO + SeverityInfo2 Severity = 1 // INFO2 + SeverityInfo3 Severity = 2 // INFO3 + SeverityInfo4 Severity = 3 // INFO4 + + // A warning log record. Not an error but is likely more important than an + // informational event. + SeverityWarn1 Severity = 4 // WARN + SeverityWarn2 Severity = 5 // WARN2 + SeverityWarn3 Severity = 6 // WARN3 + SeverityWarn4 Severity = 7 // WARN4 + + // An error log record. Something went wrong. + SeverityError1 Severity = 8 // ERROR + SeverityError2 Severity = 9 // ERROR2 + SeverityError3 Severity = 10 // ERROR3 + SeverityError4 Severity = 11 // ERROR4 + + // A fatal log record such as application or system crash. + SeverityFatal1 Severity = 12 // FATAL + SeverityFatal2 Severity = 13 // FATAL2 + SeverityFatal3 Severity = 14 // FATAL3 + SeverityFatal4 Severity = 15 // FATAL4 + + // Convenience definitions for the base severity of each level. + SeverityTrace = SeverityTrace1 + SeverityDebug = SeverityDebug1 + SeverityInfo = SeverityInfo1 + SeverityWarn = SeverityWarn1 + SeverityError = SeverityError1 + SeverityFatal = SeverityFatal1 +) + +// Severity returns the receiver translated to a [log.Severity]. +// +// It implements [Severitier]. +func (s Severity) Severity() log.Severity { + // Unknown defaults to log.SeverityUndefined. + return translations[s] +} + +var translations = map[Severity]log.Severity{ + SeverityTrace1: log.SeverityTrace1, + SeverityTrace2: log.SeverityTrace2, + SeverityTrace3: log.SeverityTrace3, + SeverityTrace4: log.SeverityTrace4, + SeverityDebug1: log.SeverityDebug1, + SeverityDebug2: log.SeverityDebug2, + SeverityDebug3: log.SeverityDebug3, + SeverityDebug4: log.SeverityDebug4, + SeverityInfo1: log.SeverityInfo1, + SeverityInfo2: log.SeverityInfo2, + SeverityInfo3: log.SeverityInfo3, + SeverityInfo4: log.SeverityInfo4, + SeverityWarn1: log.SeverityWarn1, + SeverityWarn2: log.SeverityWarn2, + SeverityWarn3: log.SeverityWarn3, + SeverityWarn4: log.SeverityWarn4, + SeverityError1: log.SeverityError1, + SeverityError2: log.SeverityError2, + SeverityError3: log.SeverityError3, + SeverityError4: log.SeverityError4, + SeverityFatal1: log.SeverityFatal1, + SeverityFatal2: log.SeverityFatal2, + SeverityFatal3: log.SeverityFatal3, + SeverityFatal4: log.SeverityFatal4, +} + +// A SeverityVar is a [Severity] variable, to allow a [LogProcessor] severity +// to change dynamically. It implements [Severitier] as well as a Set method, +// and it is safe for use by multiple goroutines. +// +// The zero SeverityVar corresponds to [SeverityInfo]. +type SeverityVar struct { + val atomic.Int64 +} + +// Severity returns v's severity. +func (v *SeverityVar) Severity() log.Severity { + return Severity(int(v.val.Load())).Severity() +} + +// Set sets v's Severity to l. +func (v *SeverityVar) Set(l Severity) { + v.val.Store(int64(l)) +} + +// A Severitier provides a [log.Severity] value. +type Severitier interface { + Severity() log.Severity +} diff --git a/processors/minsev/severity_test.go b/processors/minsev/severity_test.go new file mode 100644 index 00000000000..c4246fc430f --- /dev/null +++ b/processors/minsev/severity_test.go @@ -0,0 +1,38 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package minsev // import "go.opentelemetry.io/contrib/processors/minsev" + +import ( + "sync" + "testing" + + "go.opentelemetry.io/otel/log" +) + +func TestSeverityVarConcurrentSafe(t *testing.T) { + var ( + sev SeverityVar + wg sync.WaitGroup + ) + + wg.Add(1) + go func() { + defer wg.Done() + for s := SeverityTrace1; s <= SeverityFatal4; s++ { + sev.Set(s) + } + }() + + wg.Add(1) + go func() { + defer wg.Done() + var got log.Severity + for i := SeverityFatal4 - SeverityTrace1; i >= 0; i-- { + got = sev.Severity() + } + _ = got + }() + + wg.Wait() +}