feat: add filtering to logger (#15212)

2023-03-13 13:16:20 +00:00
parent abd4ac0790
commit ea8c76eb65
35 changed files with 285 additions and 188 deletions
@@ -31,6 +31,12 @@ 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) - 2023-0X-XX -->
+<!-- Wait for https://github.com/rs/zerolog/pull/527 to be merged -->

- [#15261](https://github.com/cosmos/cosmos-sdk/pull/15261): Provide `log.NewTestLogger(*testing.T)` function to create new log.Logger associated with a test
+## [v0.1.0](https://github.com/cosmos/cosmos-sdk/releases/tag/log/v0.1.0) - 2023-03-13
+
+* 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.
@@ -2,9 +2,13 @@ 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
@@ -1,5 +1,7 @@
 github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/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/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=
@@ -10,8 +12,34 @@ github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINE
 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=
@@ -1,5 +1,17 @@
 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
@@ -7,7 +19,66 @@ const defaultLogLevelKey = "*"
 // (* 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
 }
@@ -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"))
+}
@@ -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
 }

@@ -51,7 +51,7 @@ func NewNopLogger() Logger {
 // NewLogger returns a new logger that writes to the given destination.
 //
 // Typical usage from a main function is:
-//    logger := log.NewLogger(os.Stderr)
+// logger := log.NewLogger(os.Stderr)
 //
 // Stderr is the typical destination for logs,
 // so that any output from your application can still be piped to other processes.
@@ -102,18 +102,23 @@ 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()
+		// TODO(@julienrbrt) wait for https://github.com/rs/zerolog/pull/527 to be merged
+		// keys, err := e.GetKeys()
+		// if err != nil {
+		// 	panic(err)
+		// }
+
 		keys := []string{}
+
 		for _, key := range keys {
 			if filter(key, lvl.String()) {
 				e.Discard()