From 4a895a245ab794e3ae965783843a9fbc793083bc Mon Sep 17 00:00:00 2001 From: Abhinav Gupta Date: Tue, 16 Aug 2022 09:01:46 -0700 Subject: [PATCH] zapcore: Add LevelOf(LevelEnabler), UnknownLevel (#1147) Add a new function LevelOf that reports the minimum enabled log level for a LevelEnabler. This works by looping through all known Zap levels in-order, returning the newly introduced UnknownLevel if none of the known levels are enabled. A LevelEnabler or Core implementation may implement the Level() Level method to override and optimize this behavior. AtomicLevel already implemented this method. This change adds the method to all Core implementations shipped with Zap. Note: UnknownLevel is set at FatalLevel+1 to account for the possibility that users of Zap are using DebugLevel-1 as their own custom log level--even though this isn't supported, it's preferable not to break these users. Users are less likely to use FatalLevel+1 since Fatal means "exit the application." Refs #1144 Supersedes #1143, which was not backwards compatible Refs GO-1586 --- internal/level_enabler.go | 35 ++++++++++++++++ level.go | 3 ++ zapcore/core.go | 9 +++++ zapcore/core_test.go | 4 ++ zapcore/hook.go | 9 +++++ zapcore/hook_test.go | 9 +++++ zapcore/increase_level.go | 9 +++++ zapcore/increase_level_test.go | 7 ++++ zapcore/level.go | 42 ++++++++++++++++++++ zapcore/level_test.go | 66 +++++++++++++++++++++++++++---- zapcore/sampler.go | 11 +++++- zapcore/sampler_test.go | 16 +++++++- zapcore/tee.go | 17 +++++++- zapcore/tee_test.go | 38 ++++++++++++++++++ zaptest/observer/observer.go | 12 +++++- zaptest/observer/observer_test.go | 6 ++- 16 files changed, 279 insertions(+), 14 deletions(-) create mode 100644 internal/level_enabler.go diff --git a/internal/level_enabler.go b/internal/level_enabler.go new file mode 100644 index 000000000..5f3e3f1b9 --- /dev/null +++ b/internal/level_enabler.go @@ -0,0 +1,35 @@ +// Copyright (c) 2022 Uber Technologies, Inc. +// +// Permission is hereby granted, free of charge, to any person obtaining a copy +// of this software and associated documentation files (the "Software"), to deal +// in the Software without restriction, including without limitation the rights +// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +// copies of the Software, and to permit persons to whom the Software is +// furnished to do so, subject to the following conditions: +// +// The above copyright notice and this permission notice shall be included in +// all copies or substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN +// THE SOFTWARE. + +package internal + +import "go.uber.org/zap/zapcore" + +// LeveledEnabler is an interface satisfied by LevelEnablers that are able to +// report their own level. +// +// This interface is defined to use more conveniently in tests and non-zapcore +// packages. +// This cannot be imported from zapcore because of the cyclic dependency. +type LeveledEnabler interface { + zapcore.LevelEnabler + + Level() zapcore.Level +} diff --git a/level.go b/level.go index 8f86c430f..db951e19a 100644 --- a/level.go +++ b/level.go @@ -22,6 +22,7 @@ package zap import ( "go.uber.org/atomic" + "go.uber.org/zap/internal" "go.uber.org/zap/zapcore" ) @@ -70,6 +71,8 @@ type AtomicLevel struct { l *atomic.Int32 } +var _ internal.LeveledEnabler = AtomicLevel{} + // NewAtomicLevel creates an AtomicLevel with InfoLevel and above logging // enabled. func NewAtomicLevel() AtomicLevel { diff --git a/zapcore/core.go b/zapcore/core.go index a1ef8b034..9dfd64051 100644 --- a/zapcore/core.go +++ b/zapcore/core.go @@ -69,6 +69,15 @@ type ioCore struct { out WriteSyncer } +var ( + _ Core = (*ioCore)(nil) + _ leveledEnabler = (*ioCore)(nil) +) + +func (c *ioCore) Level() Level { + return LevelOf(c.LevelEnabler) +} + func (c *ioCore) With(fields []Field) Core { clone := c.clone() addFields(clone.enc, fields) diff --git a/zapcore/core_test.go b/zapcore/core_test.go index 0542270ca..1311097cc 100644 --- a/zapcore/core_test.go +++ b/zapcore/core_test.go @@ -82,6 +82,10 @@ func TestIOCore(t *testing.T) { ).With([]Field{makeInt64Field("k", 1)}) defer assert.NoError(t, core.Sync(), "Expected Syncing a temp file to succeed.") + t.Run("LevelOf", func(t *testing.T) { + assert.Equal(t, InfoLevel, LevelOf(core), "Incorrect Core Level") + }) + if ce := core.Check(Entry{Level: DebugLevel, Message: "debug"}, nil); ce != nil { ce.Write(makeInt64Field("k", 2)) } diff --git a/zapcore/hook.go b/zapcore/hook.go index 5db4afb30..198def991 100644 --- a/zapcore/hook.go +++ b/zapcore/hook.go @@ -27,6 +27,11 @@ type hooked struct { funcs []func(Entry) error } +var ( + _ Core = (*hooked)(nil) + _ leveledEnabler = (*hooked)(nil) +) + // RegisterHooks wraps a Core and runs a collection of user-defined callback // hooks each time a message is logged. Execution of the callbacks is blocking. // @@ -40,6 +45,10 @@ func RegisterHooks(core Core, hooks ...func(Entry) error) Core { } } +func (h *hooked) Level() Level { + return LevelOf(h.Core) +} + func (h *hooked) Check(ent Entry, ce *CheckedEntry) *CheckedEntry { // Let the wrapped Core decide whether to log this message or not. This // also gives the downstream a chance to register itself directly with the diff --git a/zapcore/hook_test.go b/zapcore/hook_test.go index 0764888ab..46e3c3588 100644 --- a/zapcore/hook_test.go +++ b/zapcore/hook_test.go @@ -27,6 +27,7 @@ import ( "go.uber.org/zap/zaptest/observer" "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" ) func TestHooks(t *testing.T) { @@ -42,6 +43,10 @@ func TestHooks(t *testing.T) { for _, tt := range tests { fac, logs := observer.New(tt.coreLevel) + + // sanity check + require.Equal(t, tt.coreLevel, LevelOf(fac), "Original logger has the wrong level") + intField := makeInt64Field("foo", 42) ent := Entry{Message: "bar", Level: tt.entryLevel} @@ -57,6 +62,10 @@ func TestHooks(t *testing.T) { ce.Write() } + t.Run("LevelOf", func(t *testing.T) { + assert.Equal(t, tt.coreLevel, LevelOf(h), "Wrapped logger has the wrong log level") + }) + if tt.expectCall { assert.Equal(t, 1, called, "Expected to call hook once.") assert.Equal( diff --git a/zapcore/increase_level.go b/zapcore/increase_level.go index 5a1749261..7a11237ae 100644 --- a/zapcore/increase_level.go +++ b/zapcore/increase_level.go @@ -27,6 +27,11 @@ type levelFilterCore struct { level LevelEnabler } +var ( + _ Core = (*levelFilterCore)(nil) + _ leveledEnabler = (*levelFilterCore)(nil) +) + // NewIncreaseLevelCore creates a core that can be used to increase the level of // an existing Core. It cannot be used to decrease the logging level, as it acts // as a filter before calling the underlying core. If level decreases the log level, @@ -45,6 +50,10 @@ func (c *levelFilterCore) Enabled(lvl Level) bool { return c.level.Enabled(lvl) } +func (c *levelFilterCore) Level() Level { + return LevelOf(c.level) +} + func (c *levelFilterCore) With(fields []Field) Core { return &levelFilterCore{c.core.With(fields), c.level} } diff --git a/zapcore/increase_level_test.go b/zapcore/increase_level_test.go index acb8700f7..547794fe7 100644 --- a/zapcore/increase_level_test.go +++ b/zapcore/increase_level_test.go @@ -82,6 +82,9 @@ func TestIncreaseLevel(t *testing.T) { t.Run(msg, func(t *testing.T) { logger, logs := observer.New(tt.coreLevel) + // sanity check + require.Equal(t, tt.coreLevel, LevelOf(logger), "Original logger has the wrong level") + filteredLogger, err := NewIncreaseLevelCore(logger, tt.increaseLevel) if tt.wantErr { require.Error(t, err) @@ -95,6 +98,10 @@ func TestIncreaseLevel(t *testing.T) { require.NoError(t, err) + t.Run("LevelOf", func(t *testing.T) { + assert.Equal(t, tt.increaseLevel, LevelOf(filteredLogger), "Filtered logger has the wrong level") + }) + for l := DebugLevel; l <= FatalLevel; l++ { enabled := filteredLogger.Enabled(l) entry := Entry{Level: l} diff --git a/zapcore/level.go b/zapcore/level.go index 56e88dc0c..e01a24131 100644 --- a/zapcore/level.go +++ b/zapcore/level.go @@ -53,6 +53,11 @@ const ( _minLevel = DebugLevel _maxLevel = FatalLevel + + // InvalidLevel is an invalid value for Level. + // + // Core implementations may panic if they see messages of this level. + InvalidLevel = _maxLevel + 1 ) // ParseLevel parses a level based on the lower-case or all-caps ASCII @@ -67,6 +72,43 @@ func ParseLevel(text string) (Level, error) { return level, err } +type leveledEnabler interface { + LevelEnabler + + Level() Level +} + +// LevelOf reports the minimum enabled log level for the given LevelEnabler +// from Zap's supported log levels, or [InvalidLevel] if none of them are +// enabled. +// +// A LevelEnabler may implement a 'Level() Level' method to override the +// behavior of this function. +// +// func (c *core) Level() Level { +// return c.currentLevel +// } +// +// It is recommended that [Core] implementations that wrap other cores use +// LevelOf to retrieve the level of the wrapped core. For example, +// +// func (c *coreWrapper) Level() Level { +// return zapcore.LevelOf(c.wrappedCore) +// } +func LevelOf(enab LevelEnabler) Level { + if lvler, ok := enab.(leveledEnabler); ok { + return lvler.Level() + } + + for lvl := _minLevel; lvl <= _maxLevel; lvl++ { + if enab.Enabled(lvl) { + return lvl + } + } + + return InvalidLevel +} + // String returns a lower-case ASCII representation of the log level. func (l Level) String() string { switch l { diff --git a/zapcore/level_test.go b/zapcore/level_test.go index c4a120538..454332258 100644 --- a/zapcore/level_test.go +++ b/zapcore/level_test.go @@ -31,14 +31,15 @@ import ( func TestLevelString(t *testing.T) { tests := map[Level]string{ - DebugLevel: "debug", - InfoLevel: "info", - WarnLevel: "warn", - ErrorLevel: "error", - DPanicLevel: "dpanic", - PanicLevel: "panic", - FatalLevel: "fatal", - Level(-42): "Level(-42)", + DebugLevel: "debug", + InfoLevel: "info", + WarnLevel: "warn", + ErrorLevel: "error", + DPanicLevel: "dpanic", + PanicLevel: "panic", + FatalLevel: "fatal", + Level(-42): "Level(-42)", + InvalidLevel: "Level(6)", // InvalidLevel does not have a name } for lvl, stringLevel := range tests { @@ -197,3 +198,52 @@ func TestLevelAsFlagValue(t *testing.T) { "Unexpected error output from invalid flag input.", ) } + +// enablerWithCustomLevel is a LevelEnabler that implements a custom Level +// method. +type enablerWithCustomLevel struct{ lvl Level } + +var _ leveledEnabler = (*enablerWithCustomLevel)(nil) + +func (l *enablerWithCustomLevel) Enabled(lvl Level) bool { + return l.lvl.Enabled(lvl) +} + +func (l *enablerWithCustomLevel) Level() Level { + return l.lvl +} + +func TestLevelOf(t *testing.T) { + tests := []struct { + desc string + give LevelEnabler + want Level + }{ + {desc: "debug", give: DebugLevel, want: DebugLevel}, + {desc: "info", give: InfoLevel, want: InfoLevel}, + {desc: "warn", give: WarnLevel, want: WarnLevel}, + {desc: "error", give: ErrorLevel, want: ErrorLevel}, + {desc: "dpanic", give: DPanicLevel, want: DPanicLevel}, + {desc: "panic", give: PanicLevel, want: PanicLevel}, + {desc: "fatal", give: FatalLevel, want: FatalLevel}, + { + desc: "leveledEnabler", + give: &enablerWithCustomLevel{lvl: InfoLevel}, + want: InfoLevel, + }, + { + desc: "noop", + give: NewNopCore(), // always disabled + want: InvalidLevel, + }, + } + + for _, tt := range tests { + tt := tt + t.Run(tt.desc, func(t *testing.T) { + t.Parallel() + + assert.Equal(t, tt.want, LevelOf(tt.give), "Reported level did not match.") + }) + } +} diff --git a/zapcore/sampler.go b/zapcore/sampler.go index a15b7c910..dc518055a 100644 --- a/zapcore/sampler.go +++ b/zapcore/sampler.go @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Uber Technologies, Inc. +// Copyright (c) 2016-2022 Uber Technologies, Inc. // // Permission is hereby granted, free of charge, to any person obtaining a copy // of this software and associated documentation files (the "Software"), to deal @@ -175,6 +175,11 @@ type sampler struct { hook func(Entry, SamplingDecision) } +var ( + _ Core = (*sampler)(nil) + _ leveledEnabler = (*sampler)(nil) +) + // NewSampler creates a Core that samples incoming entries, which // caps the CPU and I/O load of logging while attempting to preserve a // representative subset of your logs. @@ -192,6 +197,10 @@ func NewSampler(core Core, tick time.Duration, first, thereafter int) Core { return NewSamplerWithOptions(core, tick, first, thereafter) } +func (s *sampler) Level() Level { + return LevelOf(s.Core) +} + func (s *sampler) With(fields []Field) Core { return &sampler{ Core: s.Core.With(fields), diff --git a/zapcore/sampler_test.go b/zapcore/sampler_test.go index f19a6fc9e..194427a65 100644 --- a/zapcore/sampler_test.go +++ b/zapcore/sampler_test.go @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Uber Technologies, Inc. +// Copyright (c) 2016-2022 Uber Technologies, Inc. // // Permission is hereby granted, free of charge, to any person obtaining a copy // of this software and associated documentation files (the "Software"), to deal @@ -88,6 +88,19 @@ func TestSampler(t *testing.T) { } } +func TestLevelOfSampler(t *testing.T) { + levels := []Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel, DPanicLevel, PanicLevel, FatalLevel} + for _, lvl := range levels { + lvl := lvl + t.Run(lvl.String(), func(t *testing.T) { + t.Parallel() + + sampler, _ := fakeSampler(lvl, time.Minute, 2, 3) + assert.Equal(t, lvl, LevelOf(sampler), "Sampler level did not match.") + }) + } +} + func TestSamplerDisabledLevels(t *testing.T) { sampler, logs := fakeSampler(InfoLevel, time.Minute, 1, 100) @@ -232,7 +245,6 @@ func TestSamplerConcurrent(t *testing.T) { int(dropped.Load()), "Unexpected number of logs dropped", ) - } func TestSamplerRaces(t *testing.T) { diff --git a/zapcore/tee.go b/zapcore/tee.go index 07a32eef9..9bb32f055 100644 --- a/zapcore/tee.go +++ b/zapcore/tee.go @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Uber Technologies, Inc. +// Copyright (c) 2016-2022 Uber Technologies, Inc. // // Permission is hereby granted, free of charge, to any person obtaining a copy // of this software and associated documentation files (the "Software"), to deal @@ -24,6 +24,11 @@ import "go.uber.org/multierr" type multiCore []Core +var ( + _ leveledEnabler = multiCore(nil) + _ Core = multiCore(nil) +) + // NewTee creates a Core that duplicates log entries into two or more // underlying Cores. // @@ -48,6 +53,16 @@ func (mc multiCore) With(fields []Field) Core { return clone } +func (mc multiCore) Level() Level { + minLvl := _maxLevel // mc is never empty + for i := range mc { + if lvl := LevelOf(mc[i]); lvl < minLvl { + minLvl = lvl + } + } + return minLvl +} + func (mc multiCore) Enabled(lvl Level) bool { for i := range mc { if mc[i].Enabled(lvl) { diff --git a/zapcore/tee_test.go b/zapcore/tee_test.go index e44c21c01..b2b9c9dc0 100644 --- a/zapcore/tee_test.go +++ b/zapcore/tee_test.go @@ -49,6 +49,44 @@ func TestTeeUnusualInput(t *testing.T) { }) } +func TestLevelOfTee(t *testing.T) { + debugLogger, _ := observer.New(DebugLevel) + warnLogger, _ := observer.New(WarnLevel) + + tests := []struct { + desc string + give []Core + want Level + }{ + {desc: "empty", want: InvalidLevel}, + { + desc: "debug", + give: []Core{debugLogger}, + want: DebugLevel, + }, + { + desc: "warn", + give: []Core{warnLogger}, + want: WarnLevel, + }, + { + desc: "debug and warn", + give: []Core{warnLogger, debugLogger}, + want: DebugLevel, + }, + } + + for _, tt := range tests { + tt := tt + t.Run(tt.desc, func(t *testing.T) { + t.Parallel() + + core := NewTee(tt.give...) + assert.Equal(t, tt.want, LevelOf(core), "Level of Tee core did not match.") + }) + } +} + func TestTeeCheck(t *testing.T) { withTee(func(tee Core, debugLogs, warnLogs *observer.ObservedLogs) { debugEntry := Entry{Level: DebugLevel, Message: "log-at-debug"} diff --git a/zaptest/observer/observer.go b/zaptest/observer/observer.go index 997f39f09..f77f1308b 100644 --- a/zaptest/observer/observer.go +++ b/zaptest/observer/observer.go @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Uber Technologies, Inc. +// Copyright (c) 2016-2022 Uber Technologies, Inc. // // Permission is hereby granted, free of charge, to any person obtaining a copy // of this software and associated documentation files (the "Software"), to deal @@ -29,6 +29,7 @@ import ( "sync" "time" + "go.uber.org/zap/internal" "go.uber.org/zap/zapcore" ) @@ -158,6 +159,15 @@ type contextObserver struct { context []zapcore.Field } +var ( + _ zapcore.Core = (*contextObserver)(nil) + _ internal.LeveledEnabler = (*contextObserver)(nil) +) + +func (co *contextObserver) Level() zapcore.Level { + return zapcore.LevelOf(co.LevelEnabler) +} + func (co *contextObserver) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry { if co.Enabled(ent.Level) { return ce.AddCore(ent, co) diff --git a/zaptest/observer/observer_test.go b/zaptest/observer/observer_test.go index 9f179d02e..2a901b1ce 100644 --- a/zaptest/observer/observer_test.go +++ b/zaptest/observer/observer_test.go @@ -1,4 +1,4 @@ -// Copyright (c) 2016 Uber Technologies, Inc. +// Copyright (c) 2016-2022 Uber Technologies, Inc. // // Permission is hereby granted, free of charge, to any person obtaining a copy // of this software and associated documentation files (the "Software"), to deal @@ -41,6 +41,10 @@ func TestObserver(t *testing.T) { observer, logs := New(zap.InfoLevel) assertEmpty(t, logs) + t.Run("LevelOf", func(t *testing.T) { + assert.Equal(t, zap.InfoLevel, zapcore.LevelOf(observer), "Observer reported the wrong log level.") + }) + assert.NoError(t, observer.Sync(), "Unexpected failure in no-op Sync") obs := zap.New(observer).With(zap.Int("i", 1))