Skip to content

Commit

Permalink
refactor(log): restore customized nop logger (#15257)
Browse files Browse the repository at this point in the history
  • Loading branch information
mark-rushakoff authored Mar 3, 2023
1 parent 8fb95f0 commit 08be7ab
Show file tree
Hide file tree
Showing 2 changed files with 46 additions and 16 deletions.
29 changes: 24 additions & 5 deletions log/bench_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -94,9 +94,9 @@ func BenchmarkLoggers(b *testing.B) {
}
})

// The nop logger we use in tests,
// The nop logger we use expose in the public API,
// also useful as a reference for how expensive zerolog is.
b.Run("nop logger", func(b *testing.B) {
b.Run("specialized nop logger", func(b *testing.B) {
for _, bc := range nopCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
Expand All @@ -108,11 +108,30 @@ func BenchmarkLoggers(b *testing.B) {
})
}
})

// To compare with the custom nop logger.
// The zerolog wrapper is about 1/3 the speed of the specialized nop logger,
// so we offer the specialized version in the exported API.
b.Run("zerolog nop logger", func(b *testing.B) {
for _, bc := range nopCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
logger := log.NewCustomLogger(zerolog.Nop())

for i := 0; i < b.N; i++ {
logger.Info(message, bc.keyVals...)
}
})
}
})
}

func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
b.ReportAllocs()

errorToLog := errors.New("error")
byteSliceToLog := []byte{0xde, 0xad, 0xbe, 0xef}

b.Run("logger structured", func(b *testing.B) {
zl := zerolog.New(io.Discard)
var logger log.Logger = log.NewCustomLogger(zl)
Expand All @@ -123,8 +142,8 @@ func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
zerolog.Error().
Int64("foo", 100000).
Str("bar", "foo").
Bytes("other", []byte{0xde, 0xad, 0xbe, 0xef}).
Err(errors.New("error")).
Bytes("other", byteSliceToLog).
Err(errorToLog).
Msg(message)
}
})
Expand All @@ -135,7 +154,7 @@ func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
for i := 0; i < b.N; i++ {
logger.Info(message, "foo", 100000)
logger.Info(message, "foo", "foo")
logger.Error(message, "foo", 100000, "bar", "foo", "other", []byte{0xde, 0xad, 0xbe, 0xef}, "error", errors.New("error"))
logger.Error(message, "foo", 100000, "bar", "foo", "other", byteSliceToLog, "error", errorToLog)
}
})
}
33 changes: 22 additions & 11 deletions log/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,11 +21,11 @@ type Logger interface {
// The key of the tuple must be a string.
Info(msg string, keyVals ...any)

// Error takes a message and a set of key/value pairs and logs with level DEBUG.
// Error takes a message and a set of key/value pairs and logs with level ERR.
// The key of the tuple must be a string.
Error(msg string, keyVals ...any)

// Debug takes a message and a set of key/value pairs and logs with level ERR.
// Debug takes a message and a set of key/value pairs and logs with level DEBUG.
// The key of the tuple must be a string.
Debug(msg string, keyVals ...any)

Expand All @@ -42,13 +42,13 @@ type zeroLogWrapper struct {
*zerolog.Logger
}

// NewNopLogger returns a new logger that does nothing
// NewNopLogger returns a new logger that does nothing.
func NewNopLogger() Logger {
logger := zerolog.Nop()
return zeroLogWrapper{&logger}
// The custom nopLogger is about 3x faster than a zeroLogWrapper with zerolog.Nop().
return nopLogger{}
}

// NewLogger returns a new logger
// NewLogger returns a new logger that writes to stdout.
func NewLogger() Logger {
output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.Kitchen}
logger := zerolog.New(output).With().Timestamp().Logger()
Expand All @@ -62,7 +62,7 @@ func NewLoggerWithKV(key, value string) Logger {
return zeroLogWrapper{&logger}
}

// NewCustomLogger returns a new logger with the given zerolog logger
// NewCustomLogger returns a new logger with the given zerolog logger.
func NewCustomLogger(logger zerolog.Logger) Logger {
return zeroLogWrapper{&logger}
}
Expand All @@ -85,19 +85,19 @@ func (l zeroLogWrapper) Debug(msg string, keyVals ...interface{}) {
l.Logger.Debug().Fields(keyVals).Msg(msg)
}

// With returns a new wrapped logger with additional context provided by a set
// With returns a new wrapped logger with additional context provided by a set.
func (l zeroLogWrapper) With(keyVals ...interface{}) Logger {
logger := l.Logger.With().Fields(keyVals).Logger()
return zeroLogWrapper{&logger}
}

// Impl returns the underlying zerolog logger
// It can be used to used zerolog structured API directly instead of the wrapper
// Impl returns the underlying zerolog logger.
// It can be used to used zerolog structured API directly instead of the wrapper.
func (l zeroLogWrapper) Impl() interface{} {
return l.Logger
}

// FilterKeys returns a new logger that filters out all key/value pairs that do not match the filter
// FilterKeys returns a new logger that filters out all key/value pairs that do not match the filter.
// This functions assumes that the logger is a zerolog.Logger, which is the case for the logger returned by log.NewLogger()
// NOTE: filtering has a performance impact on the logger
func FilterKeys(logger Logger, filter func(key, level string) bool) Logger {
Expand All @@ -120,3 +120,14 @@ func FilterKeys(logger Logger, filter func(key, level string) bool) Logger {

return NewCustomLogger(filteredLogger)
}

// nopLogger is a Logger that does nothing when called.
// See the "specialized nop logger" benchmark and compare with the "zerolog nop logger" benchmark.
// The custom implementation is about 3x faster.
type nopLogger struct{}

func (nopLogger) Info(string, ...any) {}
func (nopLogger) Error(string, ...any) {}
func (nopLogger) Debug(string, ...any) {}
func (nopLogger) With(...any) Logger { return nopLogger{} }
func (nopLogger) Impl() any { return nopLogger{} }

0 comments on commit 08be7ab

Please sign in to comment.