feat: add filtering to logger

log/CHANGELOG.md

@@ -31,6 +31,9 @@ Ref: https://keepachangelog.com/en/1.0.0/
 
 ## [Unreleased]
 
-### Improvements
+## [v1.0.0](https://github.com/cosmos/cosmos-sdk/releases/tag/log/v1.0.0) - 2022-03-08
 
-- [#15261](https://github.com/cosmos/cosmos-sdk/pull/15261): Provide `log.NewTestLogger(*testing.T)` function to create new log.Logger associated with a test
+* Introducing a standalone SDK logger package (`comossdk.io/log`).
+  It replaces CometBFT logger and provides a common interface for all SDK components.
+  The default logger (`NewLogger`) is using [zerolog](https://github.com/rs/zerolog),
+  but it can be easily replaced with any implementation that implements the `log.Logger` interface.

log/go.mod

@@ -2,10 +2,17 @@ module cosmossdk.io/log
 
 go 1.20
 
-require github.com/rs/zerolog v1.29.0
+require (
+	github.com/rs/zerolog v1.29.0
+	gotest.tools/v3 v3.4.0
+)
 
 require (
+	github.com/google/go-cmp v0.5.5 // indirect
 	github.com/mattn/go-colorable v0.1.13 // indirect
 	github.com/mattn/go-isatty v0.0.16 // indirect
 	golang.org/x/sys v0.5.0 // indirect
 )
+
+// TODO wait for https://github.com/rs/zerolog/pull/527 to be merged
+replace github.com/rs/zerolog => github.com/julienrbrt/zerolog v0.0.0-20230227160104-8fd4f8ce93ff

log/go.sum

@@ -1,5 +1,9 @@
-github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
+github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
+github.com/google/go-cmp v0.5.5 h1:Khx7svrCpmxxtHBq5j2mp/xVjsi8hQMfNLvJFAlrGgU=
+github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
+github.com/julienrbrt/zerolog v0.0.0-20230227160104-8fd4f8ce93ff h1:lIa0Ro4XyRCVFomzudFIjxZW3nSP8mCb9qJ1matAS40=
+github.com/julienrbrt/zerolog v0.0.0-20230227160104-8fd4f8ce93ff/go.mod h1:Le6ESbR7hc+DP6Lt1THiV8CQSdkkNrd3R0XbEgp3ZBU=
 github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
 github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
 github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
@@ -8,10 +12,34 @@ github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peK
 github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
 github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 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/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
+golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
+golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
+golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
+golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
+golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
+golang.org/x/net v0.0.0-20201021035429-f5854403a974/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU=
+golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 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=
+golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
+golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
+golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
+golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/tools v0.1.0/go.mod h1:xkSsbof2nBLbhDlRMhhhyNLN/zl3eTqcnHD5viDpcZ0=
+golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
+golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+gotest.tools/v3 v3.4.0 h1:ZazjZUfuVeZGLAmlKKuyv3IKP5orXcwtOwDQH6YVr6o=
+gotest.tools/v3 v3.4.0/go.mod h1:CtbdzLSsqVhDgMtKsx03ird5YTGB3ar27v0u/yKBW5g=

log/level.go

@@ -1,13 +1,84 @@
 package log
 
+import (
+	"errors"
+	"fmt"
+	"strings"
+
+	"github.com/rs/zerolog"
+)
+
+// FilterFunc is a function that returns true if the log level is filtered for the given key
+// When the filter returns true, the log entry is discarded
+type FilterFunc func(key, level string) bool
+
 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
+// ParseLogLevel("consensus:debug,mempool:debug,*:error")
+//
+// This function attemps to keep the same behavior as the CometBFT ParseLogLevel
+// However the level `none` is replaced by `disabled`.
+func ParseLogLevel(levelStr string) (FilterFunc, error) {
+	if levelStr == "" {
+		return nil, errors.New("empty log level")
+	}
+
+	// prefix simple one word levels (e.g. "info") with "*"
+	l := levelStr
+	if !strings.Contains(l, ":") {
+		l = defaultLogLevelKey + ":" + l
+	}
+
+	// parse and validate the levels
+	filterMap := make(map[string]string)
+	list := strings.Split(l, ",")
+	for _, item := range list {
+		moduleAndLevel := strings.Split(item, ":")
+		if len(moduleAndLevel) != 2 {
+			return nil, fmt.Errorf("expected list in a form of \"module:level\" pairs, given pair %s, list %s", item, list)
+		}
+
+		module := moduleAndLevel[0]
+		level := moduleAndLevel[1]
+
+		if _, ok := filterMap[module]; ok {
+			return nil, fmt.Errorf("duplicate module %s in log level list %s", module, list)
+		}
+
+		if _, err := zerolog.ParseLevel(level); err != nil {
+			return nil, fmt.Errorf("invalid log level %s in log level list %s", level, list)
+		}
+
+		filterMap[module] = level
+	}
+
+	filterFunc := func(key, lvl string) bool {
+		level, ok := filterMap[key]
+		if !ok { // no level filter for this key
+			// check if there is a default level filter
+			level, ok = filterMap[defaultLogLevelKey]
+			if !ok {
+				return false
+			}
+		}
+
+		zllvl, err := zerolog.ParseLevel(lvl)
+		if err != nil {
+			panic(err)
+		}
+
+		zllevel, err := zerolog.ParseLevel(level)
+		if err != nil {
+			panic(err)
+		}
+
+		return zllvl < zllevel
+	}
+
+	return filterFunc, nil
 }

log/level_test.go

@@ -0,0 +1,47 @@
+package log_test
+
+import (
+	"testing"
+
+	"cosmossdk.io/log"
+	"gotest.tools/v3/assert"
+)
+
+func TestParseLogLevel(t *testing.T) {
+	_, err := log.ParseLogLevel("")
+	assert.Error(t, err, "empty log level")
+
+	level := "consensus:foo,mempool:debug,*:error"
+	_, err = log.ParseLogLevel(level)
+	assert.Error(t, err, "invalid log level foo in log level list [consensus:foo mempool:debug *:error]")
+
+	level = "consensus:debug,mempool:debug,*:error"
+	filter, err := log.ParseLogLevel(level)
+	assert.NilError(t, err)
+	assert.Assert(t, filter != nil)
+
+	assert.Assert(t, !filter("consensus", "debug"))
+	assert.Assert(t, !filter("consensus", "info"))
+	assert.Assert(t, !filter("consensus", "error"))
+	assert.Assert(t, !filter("mempool", "debug"))
+	assert.Assert(t, !filter("mempool", "info"))
+	assert.Assert(t, !filter("mempool", "error"))
+	assert.Assert(t, !filter("state", "error"))
+	assert.Assert(t, !filter("server", "panic"))
+
+	assert.Assert(t, filter("server", "debug"))
+	assert.Assert(t, filter("state", "debug"))
+	assert.Assert(t, filter("state", "info"))
+
+	level = "error"
+	filter, err = log.ParseLogLevel(level)
+	assert.NilError(t, err)
+	assert.Assert(t, filter != nil)
+
+	assert.Assert(t, !filter("state", "error"))
+	assert.Assert(t, !filter("consensus", "error"))
+
+	assert.Assert(t, filter("consensus", "debug"))
+	assert.Assert(t, filter("consensus", "info"))
+	assert.Assert(t, filter("state", "debug"))
+}

log/logger.go

@@ -7,15 +7,15 @@ import (
 	"github.com/rs/zerolog"
 )
 
-// Defines commons keys for logging
+// Defines commons keys for logging.
 const ModuleKey = "module"
 
-// ContextKey is used to store the logger in the context
+// 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
+// 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 {
 	// 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.
@@ -29,12 +29,12 @@ type Logger interface {
 	// 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 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 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
 }
 
@@ -102,18 +102,20 @@ func (l zeroLogWrapper) Impl() interface{} {
 }
 
 // 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 {
+// 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 FilterFunc) 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{}
+		keys, err := e.GetKeys()
+		if err != nil {
+			panic(err)
+		}
+
 		for _, key := range keys {
 			if filter(key, lvl.String()) {
 				e.Discard()