Mirrors/trufflehog
2
0
Fork 0
mirror of https://github.com/trufflesecurity/trufflehog.git synced 2024-11-10 07:04:24 +00:00
Code Issues Projects Releases Packages Wiki Activity

[THOG-643] Implement independent log level controls (#733)

Browse source 
* [THOG-643] Implement independent log level controls

There are two log level controls to mentally distinguish. Log levels
associated with a sink (e.g. stdout and streamed), and log levels
associated with a logger (e.g. a GitHub source).

The level is determined to be the minimum of the two. If a sink is at
level 0, then it will only output level 0 logs regardless of the
logger's level. This is best demonstrated by TestSinkWithName.

* Rename WithName to WithNamedLevel

* Check flush errors

* Replace IncreaseLevelCore with custom LevelCore

Adding a leveler that was less verbose would cause the initialization
fail, and therefore not be added to the core. This check is only at
the time of initialization.

An alternative approach to creating our own core is to set the child log
level equal to the parent, so initialization is guaranteed (with the
added benefit of intuitive behavior).

* Use controller if it exists, otherwise inherit parent's log level

* Cleanup some tests
This commit is contained in:
Miccah 2022-08-26 15:27:09 -05:00 committed by GitHub
parent 2452e93a80
commit f3367d7910
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
4 changed files with 653 additions and 66 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

41
pkg/log/core.go Normal file
View file

@ -0,0 +1,41 @@
package log
import (
"go.uber.org/zap/zapcore"
)
type levelFilterCore struct {
core zapcore.Core
level zapcore.LevelEnabler
}
// NewLevelCore creates a core that can be used to independently control the
// level of an existing Core. This is essentially a filter that will only log
// if both the parent and the wrapper cores are enabled.
func NewLevelCore(core zapcore.Core, level zapcore.LevelEnabler) zapcore.Core {
return &levelFilterCore{core, level}
}
func (c *levelFilterCore) Enabled(lvl zapcore.Level) bool {
return c.level.Enabled(lvl)
}
func (c *levelFilterCore) With(fields []zapcore.Field) zapcore.Core {
return &levelFilterCore{c.core.With(fields), c.level}
}
func (c *levelFilterCore) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
if !c.Enabled(ent.Level) {
return ce
}
return c.core.Check(ent, ce)
}
func (c *levelFilterCore) Write(ent zapcore.Entry, fields []zapcore.Field) error {
return c.core.Write(ent, fields)
}
func (c *levelFilterCore) Sync() error {
return c.core.Sync()
}

114
pkg/log/level.go Normal file
View file

@ -0,0 +1,114 @@
package log
import (
"sort"
"sync"
"github.com/go-logr/logr"
"github.com/go-logr/zapr"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
// TODO: Use a struct to make testing easier.
var (
// Global, default log level control.
globalLogLevel levelSetter = zap.NewAtomicLevel()
// Map of name -> level control for independently setting log levels. A new
// control is registered via WithNamedLevel. This map is never cleaned up
// and new entries will overwrite previous values. Currently, this is
// acceptable behavior because WithNamedLevel is used sparingly.
globalControls map[string]levelSetter = make(map[string]levelSetter, 16)
// globalControls is protected (both read and write) by a mutex to make it
// thread safe. Access is low frequency, so performance is not a concern.
globalControlsLock sync.Mutex
)
type levelSetter interface {
zapcore.LevelEnabler
SetLevel(zapcore.Level)
Level() zapcore.Level
}
// SetLevel sets the log level for loggers created with the default level
// controller.
func SetLevel(level int8) {
SetLevelForControl(globalLogLevel, level)
}
// SetLevelForControl sets the log level for a given control.
func SetLevelForControl(control levelSetter, level int8) {
// Zap's levels get more verbose as the number gets smaller, as explained
// by zapr here: https://github.com/go-logr/zapr#increasing-verbosity
// For example setting the level to -2 below, means log.V(2) will be enabled.
control.SetLevel(zapcore.Level(-level))
}
// SetLevelFor sets the log level for a given named control.
func SetLevelFor(name string, level int8) {
globalControlsLock.Lock()
defer globalControlsLock.Unlock()
if control, ok := globalControls[name]; ok {
SetLevelForControl(control, level)
return
}
// Create a new control so registering a control with the same name will
// inherit the existing level.
globalControls[name] = newAtomicLevelAt(level)
}
// AddLeveler adds a log level control to a logr.Logger.
func AddLeveler(l logr.Logger, control levelSetter) (logr.Logger, error) {
zapLogger, err := getZapLogger(l)
if err != nil {
return l, err
}
zapLogger = zapLogger.WithOptions(zap.WrapCore(func(core zapcore.Core) zapcore.Core {
return NewLevelCore(core, control)
}))
return zapr.NewLogger(zapLogger), nil
}
// WithNamedLevel creates a child logger with a new name and independent log
// level control (see SetLevelFor). NOTE: if name already exists, the existing
// controller will be used, otherwise a new controller is created with level
// matching the parent's log level.
func WithNamedLevel(logger logr.Logger, name string) logr.Logger {
logger = logger.WithName(name)
globalControlsLock.Lock()
defer globalControlsLock.Unlock()
var leveler levelSetter
if currentControl, ok := globalControls[name]; ok {
leveler = currentControl
} else {
leveler = newAtomicLevelAt(findLevel(logger))
globalControls[name] = leveler
}
newLogger, err := AddLeveler(logger, leveler)
if err != nil {
return logger
}
return newLogger
}
// newAtomicLevelAt is a helper function to create a zap.AtomicLevel
// initialized with a level. We cannot use zap.NewAtomicLevelAt here because of
// a quirk with logr levels (see SetLevelForControl).
func newAtomicLevelAt(level int8) zap.AtomicLevel {
control := zap.NewAtomicLevel()
SetLevelForControl(control, level)
return control
}
// findLevel probes a logr.Logger to figure out what level it is at via binary
// search. We only search [0, 128), so worst case is ~7 checks.
func findLevel(logger logr.Logger) int8 {
sink := logger.GetSink()
return int8(sort.Search(128, func(i int) bool {
return !sink.Enabled(i)
}) - 1)
}

114
pkg/log/log.go
View file

@ -2,6 +2,7 @@ package log
import (
"errors"
"fmt"
"io"
"time"
@ -13,11 +14,6 @@ import (
"go.uber.org/zap/zapcore"
)
var (
// global log level control (see SetLevel)
logLevel zap.AtomicLevel = zap.NewAtomicLevel()
)
type logConfig struct {
core zapcore.Core
cleanup func() error
@ -56,15 +52,6 @@ func New(service string, configs ...logConfig) (logr.Logger, func() error) {
return logger, firstErrorFunc(cleanupFuncs...)
}
// SetLevel sets the log level for all loggers created with WithJSONSink and
// WithConsoleSink.
func SetLevel(level int8) {
// Zap's levels get more verbose as the number gets smaller, as explained
// by zapr here: https://github.com/go-logr/zapr#increasing-verbosity
// For example setting the level to -2 below, means log.V(2) will be enabled.
logLevel.SetLevel(zapcore.Level(-level))
}
// WithSentry adds sentry integration to the logger. This configuration may
// fail, in which case, sentry will not be added and execution will continue
// normally.
@ -95,36 +82,43 @@ func WithSentry(opts sentry.ClientOptions, tags map[string]string) logConfig {
}
}
type sinkConfig struct {
encoder zapcore.Encoder
sink zapcore.WriteSyncer
level levelSetter
}
// WithJSONSink adds a JSON encoded output to the logger.
func WithJSONSink(sink io.Writer) logConfig {
return logConfig{
core: zapcore.NewCore(
zapcore.NewJSONEncoder(defaultEncoderConfig()),
zapcore.Lock(
zapcore.AddSync(sink),
),
logLevel,
),
}
func WithJSONSink(sink io.Writer, opts ...func(*sinkConfig)) logConfig {
return newCoreConfig(
zapcore.NewJSONEncoder(defaultEncoderConfig()),
zapcore.Lock(zapcore.AddSync(sink)),
globalLogLevel,
opts...,
)
}
// WithConsoleSink adds a console-style output to the logger.
func WithConsoleSink(sink io.Writer) logConfig {
return logConfig{
core: zapcore.NewCore(
zapcore.NewConsoleEncoder(defaultEncoderConfig()),
zapcore.Lock(
zapcore.AddSync(sink),
),
logLevel,
),
}
func WithConsoleSink(sink io.Writer, opts ...func(*sinkConfig)) logConfig {
return newCoreConfig(
zapcore.NewConsoleEncoder(defaultEncoderConfig()),
zapcore.Lock(zapcore.AddSync(sink)),
globalLogLevel,
opts...,
)
}
func defaultEncoderConfig() zapcore.EncoderConfig {
conf := zap.NewProductionEncoderConfig()
// Use more human-readable time format.
conf.EncodeTime = zapcore.TimeEncoderOfLayout(time.RFC3339)
conf.EncodeLevel = func(level zapcore.Level, enc zapcore.PrimitiveArrayEncoder) {
if level == zapcore.ErrorLevel {
enc.AppendString("error")
return
}
enc.AppendString(fmt.Sprintf("info-%d", -int8(level)))
}
return conf
}
@ -136,16 +130,15 @@ func WithCore(core zapcore.Core) logConfig {
// AddSentry initializes a sentry client and extends an existing
// logr.Logger with the hook.
func AddSentry(l logr.Logger, opts sentry.ClientOptions, tags map[string]string) (logr.Logger, func() error, error) {
conf := WithSentry(opts, tags)
if conf.err != nil {
return l, nil, conf.err
}
return AddSink(l, conf)
return AddSink(l, WithSentry(opts, tags))
}
// AddSink extends an existing logr.Logger with a new sink. It returns the new
// logr.Logger, a cleanup function, and an error.
func AddSink(l logr.Logger, sink logConfig) (logr.Logger, func() error, error) {
if sink.err != nil {
return l, nil, sink.err
}
zapLogger, err := getZapLogger(l)
if err != nil {
return l, nil, errors.New("unsupported logr implementation")
@ -165,6 +158,24 @@ func getZapLogger(l logr.Logger) (*zap.Logger, error) {
return nil, errors.New("not a zapr logger")
}
// WithLevel sets the sink's level to a static level. This option prevents
// changing the log level for this sink later on.
func WithLevel(level int8) func(*sinkConfig) {
return WithLeveler(
// Zap's levels get more verbose as the number gets smaller, as explained
// by zapr here: https://github.com/go-logr/zapr#increasing-verbosity
// For example setting the level to -2 below, means log.V(2) will be enabled.
zap.NewAtomicLevelAt(zapcore.Level(-level)),
)
}
// WithLeveler sets the sink's level enabler to leveler.
func WithLeveler(leveler levelSetter) func(*sinkConfig) {
return func(conf *sinkConfig) {
conf.level = leveler
}
}
// firstErrorFunc is a helper function that returns a function that executes
// all provided args and returns the first error, if any.
func firstErrorFunc(fs ...func() error) func() error {
@ -181,3 +192,28 @@ func firstErrorFunc(fs ...func() error) func() error {
return firstErr
}
}
// newCoreConfig is a helper function that creates a default sinkConfig,
// applies the options, then creates a zapcore.Core.
func newCoreConfig(
defaultEncoder zapcore.Encoder,
defaultSink zapcore.WriteSyncer,
defaultLevel levelSetter,
opts ...func(*sinkConfig),
) logConfig {
conf := sinkConfig{
encoder: defaultEncoder,
sink: defaultSink,
level: defaultLevel,
}
for _, f := range opts {
f(&conf)
}
return logConfig{
core: zapcore.NewCore(
conf.encoder,
conf.sink,
conf.level,
),
}
}

450
pkg/log/log_test.go
View file

@ -2,33 +2,52 @@ package log
import (
"bytes"
"encoding/json"
"fmt"
"io"
"sort"
"strings"
"sync"
"testing"
"time"
"github.com/getsentry/sentry-go"
"github.com/go-logr/logr"
"github.com/stretchr/testify/assert"
"go.uber.org/zap"
)
func TestNew(t *testing.T) {
var jsonBuffer, consoleBuffer bytes.Buffer
logger, sync := New("service-name",
logger, flush := New("service-name",
WithJSONSink(&jsonBuffer),
WithConsoleSink(&consoleBuffer),
)
logger.Info("yay")
assert.Nil(t, sync())
assert.Nil(t, flush())
assert.Contains(t, jsonBuffer.String(), `"logger":"service-name"`)
assert.Contains(t, jsonBuffer.String(), `"msg":"yay"`)
assert.Contains(t, consoleBuffer.String(), "info\tservice-name\tyay")
var parsedJSON map[string]any
assert.Nil(t, json.Unmarshal(jsonBuffer.Bytes(), &parsedJSON))
assert.NotEmpty(t, parsedJSON["ts"])
delete(parsedJSON, "ts")
assert.Equal(t,
map[string]any{
"level": "info-0",
"logger": "service-name",
"msg": "yay",
},
parsedJSON,
)
assert.Equal(t,
[]string{"info-0\tservice-name\tyay"},
splitLines(consoleBuffer.String()),
)
}
func TestSetLevel(t *testing.T) {
var buffer bytes.Buffer
logger, _ := New("service-name",
WithConsoleSink(&buffer),
)
defer SetLevel(0)
logger, _ := New("service-name", WithConsoleSink(&buffer))
assert.Equal(t, true, logger.GetSink().Enabled(0))
assert.Equal(t, false, logger.GetSink().Enabled(1))
@ -47,12 +66,12 @@ func TestSetLevel(t *testing.T) {
func TestWithSentryFailure(t *testing.T) {
var buffer bytes.Buffer
logger, sync := New("service-name",
logger, flush := New("service-name",
WithSentry(sentry.ClientOptions{Dsn: "fail"}, nil),
WithConsoleSink(&buffer),
)
logger.Info("yay")
assert.Nil(t, sync())
assert.Nil(t, flush())
assert.Contains(t, buffer.String(), "error configuring logger")
assert.Contains(t, buffer.String(), "yay")
@ -60,15 +79,13 @@ func TestWithSentryFailure(t *testing.T) {
func TestAddSentryFailure(t *testing.T) {
var buffer bytes.Buffer
logger, sync := New("service-name",
WithConsoleSink(&buffer),
)
logger, flush := New("service-name", WithConsoleSink(&buffer))
logger, _, err := AddSentry(logger, sentry.ClientOptions{Dsn: "fail"}, nil)
assert.NotNil(t, err)
assert.NotContains(t, err.Error(), "unsupported")
logger.Info("yay")
assert.Nil(t, sync())
assert.Nil(t, flush())
assert.Contains(t, buffer.String(), "yay")
}
@ -76,10 +93,8 @@ func TestAddSentryFailure(t *testing.T) {
func TestAddSentry(t *testing.T) {
var buffer bytes.Buffer
var sentryMessage string
logger, _ := New("service-name",
WithConsoleSink(&buffer),
)
logger, sync, err := AddSentry(logger, sentry.ClientOptions{
logger, _ := New("service-name", WithConsoleSink(&buffer))
logger, flush, err := AddSentry(logger, sentry.ClientOptions{
BeforeSend: func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event {
sentryMessage = event.Message
return nil
@ -87,19 +102,19 @@ func TestAddSentry(t *testing.T) {
}, nil)
assert.Nil(t, err)
logger.Info("yay")
logger.Error(nil, "oops")
assert.Nil(t, sync())
logger.Info("yay")
assert.Nil(t, flush())
assert.Contains(t, buffer.String(), "yay")
assert.Contains(t, buffer.String(), "oops")
assert.Contains(t, buffer.String(), "yay")
assert.Equal(t, "oops", sentryMessage)
}
func TestWithSentry(t *testing.T) {
var buffer bytes.Buffer
var sentryMessage string
logger, sync := New("service-name",
logger, flush := New("service-name",
WithConsoleSink(&buffer),
WithSentry(sentry.ClientOptions{
BeforeSend: func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event {
@ -110,7 +125,7 @@ func TestWithSentry(t *testing.T) {
)
logger.Info("yay")
logger.Error(nil, "oops")
assert.Nil(t, sync())
assert.Nil(t, flush())
assert.Contains(t, buffer.String(), "yay")
assert.Contains(t, buffer.String(), "oops")
@ -119,11 +134,11 @@ func TestWithSentry(t *testing.T) {
func TestHumanReadableTimestamp(t *testing.T) {
var buffer bytes.Buffer
logger, sync := New("service-name",
logger, flush := New("service-name",
WithConsoleSink(&buffer),
)
logger.Info("yay")
assert.Nil(t, sync())
assert.Nil(t, flush())
ts := strings.Split(buffer.String(), "\t")[0]
assert.NotContains(t, ts, "e+09")
@ -139,10 +154,10 @@ func TestAddSink(t *testing.T) {
WithConsoleSink(&buf1),
)
logger.Info("line 1")
logger, sync, err := AddSink(logger, WithConsoleSink(&buf2))
logger, flush, err := AddSink(logger, WithConsoleSink(&buf2))
assert.Nil(t, err)
logger.Info("line 2")
assert.Nil(t, sync())
assert.Nil(t, flush())
assert.Contains(t, buf1.String(), "line 1")
assert.Contains(t, buf1.String(), "line 2")
@ -150,3 +165,384 @@ func TestAddSink(t *testing.T) {
assert.NotContains(t, buf2.String(), "line 1")
assert.Contains(t, buf2.String(), "line 2")
}
func TestStaticLevelSink(t *testing.T) {
var buf1, buf2 bytes.Buffer
l1 := zap.NewAtomicLevel()
logger, flush := New(
"service-name",
WithConsoleSink(&buf1, WithLeveler(l1)),
WithConsoleSink(&buf2, WithLevel(0)),
)
logger.Info("line 1")
SetLevelForControl(l1, 1)
logger.V(1).Info("line 2")
assert.Nil(t, flush())
// buf1 should have both lines
assert.Contains(t, buf1.String(), "line 1")
assert.Contains(t, buf1.String(), "line 2")
// buf2 should only have "line 1"
assert.Contains(t, buf2.String(), "line 1")
assert.NotContains(t, buf2.String(), "line 2")
}
func TestWithLeveler(t *testing.T) {
var buf1, buf2 bytes.Buffer
l1, l2 := zap.NewAtomicLevel(), zap.NewAtomicLevel()
logger, flush := New(
"service-name",
WithConsoleSink(&buf1, WithLeveler(l1)),
WithConsoleSink(&buf2, WithLeveler(l2)),
)
SetLevelForControl(l1, 1)
SetLevelForControl(l2, 2)
logger.V(0).Info("line 1")
logger.V(1).Info("line 2")
logger.V(2).Info("line 3")
assert.Nil(t, flush())
// buf1 should have lines 1 and 2
assert.Contains(t, buf1.String(), "line 1")
assert.Contains(t, buf1.String(), "line 2")
assert.NotContains(t, buf1.String(), "line 3")
// buf2 should have all lines
assert.Contains(t, buf2.String(), "line 1")
assert.Contains(t, buf2.String(), "line 2")
assert.Contains(t, buf2.String(), "line 3")
}
func TestWithNamedLevelMoreVerbose(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
l1 := zap.NewAtomicLevel()
logger, flush := New(
"service-name",
WithConsoleSink(&buf, WithLeveler(l1)),
)
childLogger := WithNamedLevel(logger, "child")
SetLevelForControl(l1, 1)
SetLevelFor("child", 2)
logger.V(0).Info("line 1")
logger.V(1).Info("line 2")
logger.V(2).Info("line 3")
childLogger.V(0).Info("line A")
childLogger.V(1).Info("line B")
childLogger.V(2).Info("line C")
assert.Nil(t, flush())
// output should contain up to verbosity 1
assert.Equal(t, []string{
"info-0\tservice-name\tline 1",
"info-1\tservice-name\tline 2",
"info-0\tservice-name.child\tline A",
"info-1\tservice-name.child\tline B",
}, splitLines(buf.String()))
}
func TestWithNamedLevelLessVerbose(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
l1 := zap.NewAtomicLevel()
logger, flush := New(
"service-name",
WithConsoleSink(&buf, WithLeveler(l1)),
)
childLogger := WithNamedLevel(logger, "child")
SetLevelForControl(l1, 1)
SetLevelFor("child", 0)
logger.V(0).Info("line 1")
logger.V(1).Info("line 2")
logger.V(2).Info("line 3")
childLogger.V(0).Info("line A")
childLogger.V(1).Info("line B")
childLogger.V(2).Info("line C")
assert.Nil(t, flush())
// output should contain up to verbosity 1 for parent
// and verbosity 0 for child
assert.Equal(t, []string{
"info-0\tservice-name\tline 1",
"info-1\tservice-name\tline 2",
"info-0\tservice-name.child\tline A",
}, splitLines(buf.String()))
}
func TestNestedWithNamedLevel(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
grandParent, flush := New("grandParent", WithConsoleSink(&buf, WithLevel(1)))
parent := WithNamedLevel(grandParent, "parent")
child := WithNamedLevel(parent, "child")
SetLevelFor("parent", 0)
SetLevelFor("child", 2)
grandParent.V(0).Info("line 1")
parent.V(0).Info("line 2")
child.V(0).Info("line 3")
grandParent.V(1).Info("line 4")
parent.V(1).Info("line 5")
child.V(1).Info("line 6")
grandParent.V(2).Info("line 7")
parent.V(2).Info("line 8")
child.V(2).Info("line 9")
assert.Nil(t, flush())
lines := splitLines(buf.String())
assert.Equal(t, 4, len(lines))
assert.Equal(t, `info-0 grandParent line 1`, lines[0])
assert.Equal(t, `info-0 grandParent.parent line 2`, lines[1])
assert.Equal(t, `info-0 grandParent.parent.child line 3`, lines[2])
assert.Equal(t, `info-1 grandParent line 4`, lines[3])
}
func TestSiblingsWithNamedLevel(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New("parent", WithConsoleSink(&buf, WithLevel(1)))
alice := WithNamedLevel(parent, "alice")
bob := WithNamedLevel(parent, "bob")
SetLevelFor("alice", 0)
SetLevelFor("bob", 2)
parent.V(0).Info("line 1")
alice.V(0).Info("line 2")
bob.V(0).Info("line 3")
parent.V(1).Info("line 4")
alice.V(1).Info("line 5")
bob.V(1).Info("line 6")
parent.V(2).Info("line 7")
alice.V(2).Info("line 8")
bob.V(2).Info("line 9")
assert.Nil(t, flush())
lines := splitLines(buf.String())
assert.Equal(t, 5, len(lines))
assert.Equal(t, `info-0 parent line 1`, lines[0])
assert.Equal(t, `info-0 parent.alice line 2`, lines[1])
assert.Equal(t, `info-0 parent.bob line 3`, lines[2])
assert.Equal(t, `info-1 parent line 4`, lines[3])
assert.Equal(t, `info-1 parent.bob line 6`, lines[4])
}
func TestWithNamedLevelConcurrency(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New("parent", WithConsoleSink(&buf))
alice := WithNamedLevel(parent, "alice")
bob := WithNamedLevel(parent, "bob")
var wg sync.WaitGroup
f := func(logger logr.Logger) {
defer wg.Done()
for i := 0; i < 100_000; i++ {
logger.Info(fmt.Sprintf("%06d", i))
}
}
wg.Add(3)
go f(parent)
go f(alice)
go f(bob)
wg.Wait()
assert.Nil(t, flush())
logLines := splitLines(buf.String())
assert.Equal(t, 300_000, len(logLines))
sort.Slice(logLines, func(i, j int) bool {
return logLines[i] < logLines[j]
})
for i := 0; i < 100_000; i++ {
assert.Equal(t, fmt.Sprintf("info-0\tparent\t%06d", i), logLines[i])
assert.Equal(t, fmt.Sprintf("info-0\tparent.alice\t%06d", i), logLines[i+100_000])
assert.Equal(t, fmt.Sprintf("info-0\tparent.bob\t%06d", i), logLines[i+200_000])
}
}
func TestWithNamedLevelInheritance(t *testing.T) {
t.Run("child inherits parent level", func(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New("parent", WithConsoleSink(&buf, WithLevel(2)))
parent = parent.WithValues("key", "value")
// child will inherit parent's log level 2
child := WithNamedLevel(parent, "child")
parent.V(2).Info("yay")
child.V(2).Info("yay again")
assert.Nil(t, flush())
logLines := splitLines(buf.String())
assert.Equal(t, []string{
`info-2 parent yay {"key": "value"}`,
`info-2 parent.child yay again {"key": "value"}`,
}, logLines)
})
t.Run("child inherits existing named level", func(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New("parent", WithConsoleSink(&buf, WithLevel(2)))
parent = parent.WithValues("key", "value")
SetLevelFor("child", 0)
// child will inherit existing named level 0
child := WithNamedLevel(parent, "child")
parent.V(2).Info("yay")
child.V(2).Info("yay again")
assert.Nil(t, flush())
logLines := splitLines(buf.String())
assert.Equal(t, []string{`info-2 parent yay {"key": "value"}`}, logLines)
})
}
func TestExistingChildLevel(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New("parent", WithConsoleSink(&buf, WithLevel(2)))
SetLevelFor("child", 2)
// child should start with a level of 2 due to SetLevelFor above
child := WithNamedLevel(parent, "child")
parent.V(2).Info("yay")
child.V(2).Info("yay again")
assert.Nil(t, flush())
assert.Contains(t, buf.String(), "info-2\tparent\tyay")
assert.Contains(t, buf.String(), "info-2\tparent.child\tyay again")
}
func TestSinkWithNamedLevel(t *testing.T) {
var buf1, buf2 bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New(
"parent",
WithConsoleSink(&buf1, WithLevel(0)),
WithConsoleSink(&buf2, WithLevel(2)),
)
child := WithNamedLevel(parent, "child")
for level := 0; level < 3; level++ {
SetLevelFor("child", int8(level))
child.Info("")
child.V(1).Info("")
child.V(2).Info("")
}
assert.Nil(t, flush())
// buf1 should get only level 0 logs
assert.Equal(t, []string{
"info-0\tparent.child",
"info-0\tparent.child",
"info-0\tparent.child",
}, splitLines(buf1.String()))
assert.Equal(t, []string{
// child level 0
"info-0\tparent.child",
// child level 1
"info-0\tparent.child",
"info-1\tparent.child",
// child level 2
"info-0\tparent.child",
"info-1\tparent.child",
"info-2\tparent.child",
}, splitLines(buf2.String()))
}
func TestAddLeveler(t *testing.T) {
l1, l2 := zap.NewAtomicLevel(), zap.NewAtomicLevel()
logger, _ := New("parent", WithConsoleSink(io.Discard, WithLeveler(l1)))
t.Run("child level more verbose", func(t *testing.T) {
l1.SetLevel(0)
l2.SetLevel(1)
_, err := AddLeveler(logger, l2)
assert.Nil(t, err)
})
t.Run("child level less verbose", func(t *testing.T) {
l1.SetLevel(1)
l2.SetLevel(0)
_, err := AddLeveler(logger, l2)
assert.Nil(t, err)
})
}
func splitLines(s string) []string {
lines := strings.Split(strings.TrimSpace(s), "\n")
logLines := make([]string, len(lines))
for i, logLine := range lines {
// remove timestamp
logLines[i] = strings.TrimSpace(logLine[strings.Index(logLine, "\t")+1:])
}
return logLines
}
func TestFindLevel(t *testing.T) {
lvl := zap.NewAtomicLevel()
logger, _ := New("parent", WithConsoleSink(io.Discard, WithLeveler(lvl)))
for i := 0; i < 128; i++ {
i8 := int8(i)
SetLevelForControl(lvl, i8)
assert.Equal(t, i8, findLevel(logger))
}
}
func TestOverwriteWithNamedLevel(t *testing.T) {
var buf bytes.Buffer
globalControls = make(map[string]levelSetter, 16)
parent, flush := New(
"parent",
WithConsoleSink(&buf, WithLevel(2)),
)
SetLevelFor("child", 0)
child1 := WithNamedLevel(parent, "child")
child2 := WithNamedLevel(parent, "child")
SetLevelFor("child", 2)
child1.V(2).Info("")
child2.V(2).Info("")
assert.Nil(t, flush())
// buf1 should get only level 0 logs
assert.Equal(t, []string{
"info-2\tparent.child",
"info-2\tparent.child",
}, splitLines(buf.String()))
}