Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor(log): restore customized nop logger #15257

Merged
merged 1 commit into from
Mar 3, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
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.
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@julienrbrt godoc should be full, punctuated sentences.

When they are rendered on pkg.go.dev without punctuation, it looks sloppy, and it's not always clear if they are finished sentences.

Screen Shot 2023-03-03 at 9 14 11 AM

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure thing! I'll watch out, it does look sloppy without indeed 👍🏾

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is good to know, i bet there are many other areas we do this

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{} }