diff --git a/log/bench_test.go b/log/bench_test.go index f2060df924a..4c7e942fb81 100644 --- a/log/bench_test.go +++ b/log/bench_test.go @@ -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) { @@ -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) @@ -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) } }) @@ -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) } }) } diff --git a/log/logger.go b/log/logger.go index 800ef90cdd7..db0ce5b33d2 100644 --- a/log/logger.go +++ b/log/logger.go @@ -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) @@ -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() @@ -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} } @@ -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 { @@ -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{} }