feat!: use cosmossdk.io/log logger (#15011)

This commit is contained in:
Julien Robert
2023-02-27 21:36:22 +00:00
committed by GitHub
parent 35d1e7a90a
commit 5d559dd265
101 changed files with 510 additions and 403 deletions
-4
View File
@@ -30,7 +30,3 @@ Ref: https://keepachangelog.com/en/1.0.0/
# Changelog
## [Unreleased]
### Improvements
* [#15158](https://github.com/cosmos/cosmos-sdk/pull/15158) Ensure zero allocations during logging calls to Debug(), Info(), Error()
+1 -1
View File
@@ -1,3 +1,3 @@
# Log
The `cosmossdk.io/log` provides simple logging implementations for the Cosmos SDK and Cosmos SDK modules.
The `cosmossdk.io/log` provides a zerolog logging implementation for the Cosmos SDK and Cosmos SDK modules.
+37 -20
View File
@@ -2,6 +2,7 @@ package log_test
import (
"bytes"
"errors"
"io"
"testing"
"time"
@@ -10,6 +11,8 @@ import (
"github.com/rs/zerolog"
)
const message = "test message"
func BenchmarkLoggers(b *testing.B) {
b.ReportAllocs()
@@ -61,14 +64,13 @@ func BenchmarkLoggers(b *testing.B) {
},
}...)
const message = "test message"
// If running with "go test -v", print out the log messages as a sanity check.
if testing.Verbose() {
checkBuf := new(bytes.Buffer)
for _, bc := range benchCases {
checkBuf.Reset()
logger := log.ZeroLogWrapper{Logger: zerolog.New(checkBuf)}
zl := zerolog.New(checkBuf)
logger := log.NewCustomLogger(zl)
logger.Info(message, bc.keyVals...)
b.Logf("zero logger output for %s: %s", bc.name, checkBuf.String())
@@ -82,23 +84,8 @@ func BenchmarkLoggers(b *testing.B) {
for _, bc := range benchCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
logger := log.ZeroLogWrapper{Logger: zerolog.New(io.Discard)}
for i := 0; i < b.N; i++ {
logger.Info(message, bc.keyVals...)
}
})
}
})
// zerolog offers a no-op writer.
// It appears to be slower than our custom NopLogger,
// so include it in the nop benchmarks as a point of reference.
b.Run("zerolog nop", func(b *testing.B) {
for _, bc := range nopCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
logger := log.ZeroLogWrapper{Logger: zerolog.Nop()}
zl := zerolog.New(io.Discard)
logger := log.NewCustomLogger(zl)
for i := 0; i < b.N; i++ {
logger.Info(message, bc.keyVals...)
@@ -122,3 +109,33 @@ func BenchmarkLoggers(b *testing.B) {
}
})
}
func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
b.ReportAllocs()
b.Run("logger structured", func(b *testing.B) {
zl := zerolog.New(io.Discard)
var logger log.Logger = log.NewCustomLogger(zl)
zerolog := logger.Impl().(*zerolog.Logger)
for i := 0; i < b.N; i++ {
zerolog.Info().Int64("foo", 100000).Msg(message)
zerolog.Info().Str("foo", "foo").Msg(message)
zerolog.Error().
Int64("foo", 100000).
Str("bar", "foo").
Bytes("other", []byte{0xde, 0xad, 0xbe, 0xef}).
Err(errors.New("error")).
Msg(message)
}
})
b.Run("logger", func(b *testing.B) {
zl := zerolog.New(io.Discard)
var logger log.Logger = log.NewCustomLogger(zl)
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"))
}
})
}
+1 -7
View File
@@ -2,16 +2,10 @@ module cosmossdk.io/log
go 1.19
require (
github.com/cometbft/cometbft v0.37.0-alpha.3
github.com/rs/zerolog v1.29.0
)
require github.com/rs/zerolog v1.29.0
require (
github.com/go-kit/log v0.2.1 // indirect
github.com/go-logfmt/logfmt v0.5.1 // indirect
github.com/mattn/go-colorable v0.1.13 // indirect
github.com/mattn/go-isatty v0.0.16 // indirect
github.com/pkg/errors v0.9.1 // indirect
golang.org/x/sys v0.5.0 // indirect
)
-11
View File
@@ -1,11 +1,4 @@
github.com/cometbft/cometbft v0.37.0-alpha.3 h1:74F+cMr4pd1a2lFn/h4TxXmO8VWi3A2dxyoMcjlMWuQ=
github.com/cometbft/cometbft v0.37.0-alpha.3/go.mod h1:dUGbIGYoLM11xUruTTJY4Xp9FHh6Nfu3Nots8/+UNSo=
github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/go-kit/log v0.2.1 h1:MRVx0/zhvdseW+Gza6N9rVzU/IVzaeE1SFI4raAhmBU=
github.com/go-kit/log v0.2.1/go.mod h1:NwTd00d/i8cPZ3xOwwiv2PO5MOcx78fFErGNcVmBjv0=
github.com/go-logfmt/logfmt v0.5.1 h1:otpy5pqBCBZ1ng9RQ0dPu4PN7ba75Y/aA+UpowDyNVA=
github.com/go-logfmt/logfmt v0.5.1/go.mod h1:WYhtIu8zTZfxdn5+rREduYbwxfcBr/Vr6KEVveWlfTs=
github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
@@ -13,16 +6,12 @@ github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovk
github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ=
github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
github.com/rs/zerolog v1.29.0 h1:Zes4hju04hjbvkVkOhdl2HpZa+0PmVwigmo8XoORE5w=
github.com/rs/zerolog v1.29.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0=
github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.5.0 h1:MUK/U/4lj1t1oPg0HfuXDN/Z1wv31ZJ/YcPiGccS4DU=
golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
+13
View File
@@ -0,0 +1,13 @@
package log
const defaultLogLevelKey = "*"
// ParseLogLevel parses complex log level
// A comma-separated list of module:level pairs with an optional *:level pair
// (* means all other modules).
//
// Example:
// ParseLogLevel("consensus:debug,mempool:debug,*:error", "info")
func ParseLogLevel(lvl string, defaultLogLevelValue string) (func(key, level string) bool, error) {
return func(key, level string) bool { return true }, nil
}
+116 -6
View File
@@ -1,12 +1,122 @@
package log
import cmtlog "github.com/cometbft/cometbft/libs/log"
import (
"os"
"time"
// Logger is the interface that wraps the basic logging methods.
"github.com/rs/zerolog"
)
// Defines commons keys for logging
const ModuleKey = "module"
// ContextKey is used to store the logger in the context
var ContextKey struct{}
// Logger is the Cosmos SDK logger interface
// It maintains as much backward compatibility with the CometBFT logger as possible
// All functionalities of the logger are available through the Impl() method
type Logger interface {
Debug(msg string, keyvals ...interface{})
Info(msg string, keyvals ...interface{})
Error(msg string, keyvals ...interface{})
// Info takes a message and a set of key/value pairs and logs with level INFO.
// The key of the tuple must be a string.
Info(msg string, keyVals ...any)
With(keyvals ...interface{}) cmtlog.Logger
// Error takes a message and a set of key/value pairs and logs with level DEBUG.
// 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.
// The key of the tuple must be a string.
Debug(msg string, keyVals ...any)
// With returns a new wrapped logger with additional context provided by a set
With(keyVals ...any) Logger
// Impl returns the underlying logger implementation
// It is used to access the full functionalities of the underlying logger
// Advanced users can type cast the returned value to the actual logger
Impl() any
}
type zeroLogWrapper struct {
*zerolog.Logger
}
// NewNopLogger returns a new logger that does nothing
func NewNopLogger() Logger {
logger := zerolog.Nop()
return zeroLogWrapper{&logger}
}
// NewLogger returns a new logger
func NewLogger() Logger {
output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.Kitchen}
logger := zerolog.New(output).With().Timestamp().Logger()
return zeroLogWrapper{&logger}
}
// NewLoggerWithKV returns a new logger with the given key/value pair
func NewLoggerWithKV(key, value string) Logger {
output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.Kitchen}
logger := zerolog.New(output).With().Str(key, value).Timestamp().Logger()
return zeroLogWrapper{&logger}
}
// NewCustomLogger returns a new logger with the given zerolog logger
func NewCustomLogger(logger zerolog.Logger) Logger {
return zeroLogWrapper{&logger}
}
// Info takes a message and a set of key/value pairs and logs with level INFO.
// The key of the tuple must be a string.
func (l zeroLogWrapper) Info(msg string, keyVals ...interface{}) {
l.Logger.Info().Fields(keyVals).Msg(msg)
}
// Error takes a message and a set of key/value pairs and logs with level DEBUG.
// The key of the tuple must be a string.
func (l zeroLogWrapper) Error(msg string, keyVals ...interface{}) {
l.Logger.Error().Fields(keyVals).Msg(msg)
}
// Debug takes a message and a set of key/value pairs and logs with level ERR.
// The key of the tuple must be a string.
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
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
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
// 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 {
zl, ok := logger.Impl().(*zerolog.Logger)
if !ok {
panic("logger is not a zerolog.Logger")
}
filteredLogger := zl.Hook(zerolog.HookFunc(func(e *zerolog.Event, lvl zerolog.Level, _ string) {
// TODO wait for https://github.com/rs/zerolog/pull/527 to be merged
// keys := e.GetKeys()
keys := []string{}
for _, key := range keys {
if filter(key, lvl.String()) {
e.Discard()
break
}
}
}))
return NewCustomLogger(filteredLogger)
}
-19
View File
@@ -1,19 +0,0 @@
package log
import cmlog "github.com/cometbft/cometbft/libs/log"
var _ Logger = NoOp{}
type NoOp struct{}
func NewNopLogger() Logger {
return &NoOp{}
}
func (l NoOp) Debug(msg string, keyvals ...interface{}) {}
func (l NoOp) Info(msg string, keyvals ...interface{}) {}
func (l NoOp) Error(msg string, keyvals ...interface{}) {}
func (l NoOp) With(i ...interface{}) cmlog.Logger {
return l
}
+20
View File
@@ -0,0 +1,20 @@
package log
import "testing"
// reuse the same logger across all tests
var _testingLogger Logger
func NewTestingLogger() Logger {
if _testingLogger != nil {
return _testingLogger
}
if testing.Verbose() {
_testingLogger = NewLoggerWithKV(ModuleKey, "test")
} else {
_testingLogger = NewNopLogger()
}
return _testingLogger
}
-60
View File
@@ -1,60 +0,0 @@
package log
import (
"os"
"time"
cmtlog "github.com/cometbft/cometbft/libs/log"
"github.com/rs/zerolog"
)
// Defines commons keys for logging
const ModuleKey = "module"
var (
// ContextKey is used to store the logger in the context
ContextKey struct{}
_ Logger = (*ZeroLogWrapper)(nil)
)
func NewZeroLogger(key, value string) *zerolog.Logger {
output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.Kitchen}
logger := zerolog.New(output).With().Str(key, value).Timestamp().Logger()
return &logger
}
// TODO: add filtered logging in ZeroLog: https://github.com/cosmos/cosmos-sdk/pull/13236 / https://github.com/cosmos/cosmos-sdk/issues/13699#issuecomment-1354887644
// ZeroLogWrapper provides a wrapper around a zerolog.Logger instance. It implements
// Tendermint's Logger interface.
type ZeroLogWrapper struct {
zerolog.Logger
}
// Info implements Tendermint's Logger interface and logs with level INFO. A set
// of key/value tuples may be provided to add context to the log. The number of
// tuples must be even and the key of the tuple must be a string.
func (z ZeroLogWrapper) Info(msg string, keyVals ...interface{}) {
z.Logger.Info().Fields(keyVals).Msg(msg)
}
// Error implements Tendermint's Logger interface and logs with level ERR. A set
// of key/value tuples may be provided to add context to the log. The number of
// tuples must be even and the key of the tuple must be a string.
func (z ZeroLogWrapper) Error(msg string, keyVals ...interface{}) {
z.Logger.Error().Fields(keyVals).Msg(msg)
}
// Debug implements Tendermint's Logger interface and logs with level DEBUG. A set
// of key/value tuples may be provided to add context to the log. The number of
// tuples must be even and the key of the tuple must be a string.
func (z ZeroLogWrapper) Debug(msg string, keyVals ...interface{}) {
z.Logger.Debug().Fields(keyVals).Msg(msg)
}
// With returns a new wrapped logger with additional context provided by a set
// of key/value tuples. The number of tuples must be even and the key of the
// tuple must be a string.
func (z ZeroLogWrapper) With(keyVals ...interface{}) cmtlog.Logger {
return ZeroLogWrapper{z.Logger.With().Fields(keyVals).Logger()}
}