feat(log): wire logger filtering (#15601)

This commit is contained in:
Julien Robert 2023-03-30 11:48:38 +02:00 committed by GitHub
parent f3110e9d53
commit d21f58c638
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
18 changed files with 171 additions and 77 deletions

2
go.mod
View File

@ -8,7 +8,7 @@ require (
cosmossdk.io/core v0.6.1
cosmossdk.io/depinject v1.0.0-alpha.3
cosmossdk.io/errors v1.0.0-beta.7
cosmossdk.io/log v0.1.0
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d
cosmossdk.io/math v1.0.0
cosmossdk.io/store v0.1.0-alpha.1.0.20230328185921-37ba88872dbc
cosmossdk.io/x/tx v0.5.0

4
go.sum
View File

@ -45,8 +45,8 @@ cosmossdk.io/depinject v1.0.0-alpha.3 h1:6evFIgj//Y3w09bqOUOzEpFj5tsxBqdc5CfkO7z
cosmossdk.io/depinject v1.0.0-alpha.3/go.mod h1:eRbcdQ7MRpIPEM5YUJh8k97nxHpYbc3sMUnEtt8HPWU=
cosmossdk.io/errors v1.0.0-beta.7 h1:gypHW76pTQGVnHKo6QBkb4yFOJjC+sUGRc5Al3Odj1w=
cosmossdk.io/errors v1.0.0-beta.7/go.mod h1:mz6FQMJRku4bY7aqS/Gwfcmr/ue91roMEKAmDUDpBfE=
cosmossdk.io/log v0.1.0 h1:Vnexi+KzUCjmqq/m93teAxjt5biWFfZ5PI1imx2IJw8=
cosmossdk.io/log v0.1.0/go.mod h1:p95Wq6mDY3SREMc4y7+QU9Uwy3nyvfpWGD1iSaFkVFs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d h1:vRbhjJNv2/GuzU9/PX61Nl/+uyy3gmd5DKoNkQpMzSs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d/go.mod h1:CwX9BLiBruZb7lzLlRr3R231d/fVPUXk8gAdV4LQap0=
cosmossdk.io/math v1.0.0 h1:ro9w7eKx23om2tZz/VM2Pf+z2WAbGX1yDQQOJ6iGeJw=
cosmossdk.io/math v1.0.0/go.mod h1:Ygz4wBHrgc7g0N+8+MrnTfS9LLn9aaTGa9hKopuym5k=
cosmossdk.io/store v0.1.0-alpha.1.0.20230328185921-37ba88872dbc h1:9piuA+NYmhe+SyMPtMoboLw/djgDbrI3dD5TG020Tnk=

View File

@ -31,8 +31,9 @@ Ref: https://keepachangelog.com/en/1.0.0/
## [Unreleased]
<!-- ## [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 -->
## [v1.0.0](https://github.com/cosmos/cosmos-sdk/releases/tag/log/v1.0.0) - 2023-03-30
* [#15601](https://github.com/cosmos/cosmos-sdk/pull/15601) Introduce logger options. These options allow to configure the logger with filters, different level and output format.
## [v0.1.0](https://github.com/cosmos/cosmos-sdk/releases/tag/log/v0.1.0) - 2023-03-13

View File

@ -8,12 +8,12 @@ import (
"github.com/rs/zerolog"
)
const defaultLogLevelKey = "*"
// 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).

View File

@ -42,28 +42,36 @@ type zeroLogWrapper struct {
*zerolog.Logger
}
// NewNopLogger returns a new logger that does nothing.
func NewNopLogger() Logger {
// The custom nopLogger is about 3x faster than a zeroLogWrapper with zerolog.Nop().
return nopLogger{}
}
// 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.
func NewLogger(dst io.Writer) Logger {
output := zerolog.ConsoleWriter{Out: dst, TimeFormat: time.Kitchen}
logger := zerolog.New(output).With().Timestamp().Logger()
return zeroLogWrapper{&logger}
}
func NewLogger(dst io.Writer, options ...Option) Logger {
logCfg := defaultConfig
for _, opt := range options {
opt(&logCfg)
}
// NewLoggerWithKV is shorthand for NewLogger(dst).With(key, value).
func NewLoggerWithKV(dst io.Writer, key, value string) Logger {
return NewLogger(dst).With(key, value)
output := dst
if !logCfg.OutputJSON {
output = zerolog.ConsoleWriter{Out: dst, TimeFormat: time.Kitchen}
}
if logCfg.Filter != nil {
output = NewFilterWriter(output, logCfg.Filter)
}
logger := zerolog.New(output).With().Timestamp().Logger()
if logCfg.Level != zerolog.NoLevel {
logger = logger.Level(logCfg.Level)
}
return zeroLogWrapper{&logger}
}
// NewCustomLogger returns a new logger with the given zerolog logger.
@ -101,33 +109,10 @@ 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 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(@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()
break
}
}
}))
return NewCustomLogger(filteredLogger)
// NewNopLogger returns a new logger that does nothing.
func NewNopLogger() Logger {
// The custom nopLogger is about 3x faster than a zeroLogWrapper with zerolog.Nop().
return nopLogger{}
}
// nopLogger is a Logger that does nothing when called.

42
log/options.go Normal file
View File

@ -0,0 +1,42 @@
package log
import "github.com/rs/zerolog"
// defaultConfig has all the options disabled.
var defaultConfig = Config{
Level: zerolog.NoLevel,
Filter: nil,
OutputJSON: false,
}
// LoggerConfig defines configuration for the logger.
type Config struct {
Level zerolog.Level
Filter FilterFunc
OutputJSON bool
}
type Option func(*Config)
// FilterOption sets the filter for the Logger.
func FilterOption(filter FilterFunc) Option {
return func(cfg *Config) {
cfg.Filter = filter
}
}
// LevelOption sets the level for the Logger.
// Messages with a lower level will be discarded.
func LevelOption(level zerolog.Level) Option {
return func(cfg *Config) {
cfg.Level = level
}
}
// OutputJSONOption sets the output of the logger to JSON.
// By default, the logger outputs to a human-readable format.
func OutputJSONOption() Option {
return func(cfg *Config) {
cfg.OutputJSON = true
}
}

41
log/writer.go Normal file
View File

@ -0,0 +1,41 @@
package log
import (
"encoding/json"
"fmt"
"io"
)
// NewFilterWriter returns a writer that filters out all key/value pairs that do not match the filter.
// If the filter is nil, the writer will pass all events through.
// The filter function is called with the module and level of the event.
func NewFilterWriter(parent io.Writer, filter FilterFunc) io.Writer {
return &filterWriter{parent, filter}
}
type filterWriter struct {
parent io.Writer
filter FilterFunc
}
func (fw *filterWriter) Write(p []byte) (n int, err error) {
if fw.filter == nil {
return fw.parent.Write(p)
}
var event struct {
Level string `json:"level"`
Module string `json:"module"`
}
if err := json.Unmarshal(p, &event); err != nil {
return 0, fmt.Errorf("failed to unmarshal event: %w", err)
}
// only filter module keys
if fw.filter(event.Module, event.Level) {
return len(p), nil
}
return fw.parent.Write(p)
}

26
log/writer_test.go Normal file
View File

@ -0,0 +1,26 @@
package log_test
import (
"bytes"
"strings"
"testing"
"cosmossdk.io/log"
"gotest.tools/v3/assert"
)
func TestFilteredWriter(t *testing.T) {
buf := new(bytes.Buffer)
level := "consensus:debug,mempool:debug,*:error"
filter, err := log.ParseLogLevel(level)
assert.NilError(t, err)
logger := log.NewLogger(buf, log.FilterOption(filter))
logger.Debug("this log line should be displayed", log.ModuleKey, "consensus")
assert.Check(t, strings.Contains(buf.String(), "this log line should be displayed"))
buf.Reset()
logger.Debug("this log line should be filtered", log.ModuleKey, "server")
assert.Check(t, buf.Len() == 0)
}

View File

@ -169,37 +169,36 @@ func InterceptConfigsAndCreateContext(cmd *cobra.Command, customAppConfigTemplat
// CreateSDKLogger creates a the default SDK logger.
// It reads the log level and format from the server context.
func CreateSDKLogger(ctx *Context, out io.Writer) (log.Logger, error) {
var logger log.Logger
var opts []log.Option
if ctx.Viper.GetString(flags.FlagLogFormat) == cmtcfg.LogFormatJSON {
zl := zerolog.New(out).With().Timestamp().Logger()
logger = log.NewCustomLogger(zl)
} else {
logger = log.NewLogger(out)
opts = append(opts, log.OutputJSONOption())
}
// set filter level or keys for the logger if any
// check and set filter level or keys for the logger if any
logLvlStr := ctx.Viper.GetString(flags.FlagLogLevel)
if logLvlStr == "" {
return log.NewLogger(out, opts...), nil
}
logLvl, err := zerolog.ParseLevel(logLvlStr)
if err != nil {
// If the log level is not a valid zerolog level, then we try to parse it as a key filter.
filterFunc, err := log.ParseLogLevel(logLvlStr)
if err != nil {
return nil, fmt.Errorf("failed to parse log level (%s): %w", logLvlStr, err)
return nil, err
}
logger = log.FilterKeys(logger, filterFunc)
} else {
zl := logger.Impl().(*zerolog.Logger)
opts = append(opts, log.FilterOption(filterFunc))
} else if ctx.Viper.GetBool(cmtcli.TraceFlag) {
// Check if the CometBFT flag for trace logging is set if it is then setup a tracing logger in this app as well.
// Note it overrides log level passed in `log_levels`.
if ctx.Viper.GetBool(cmtcli.TraceFlag) {
logger = log.NewCustomLogger(zl.Level(zerolog.TraceLevel))
} else {
logger = log.NewCustomLogger(zl.Level(logLvl))
}
opts = append(opts, log.LevelOption(zerolog.TraceLevel))
} else {
opts = append(opts, log.LevelOption(logLvl))
}
return logger, nil
return log.NewLogger(out, opts...), nil
}
// GetServerContextFromCmd returns a Context from a command or an empty Context

View File

@ -7,7 +7,7 @@ require (
cosmossdk.io/client/v2 v2.0.0-20230309163709-87da587416ba
cosmossdk.io/core v0.6.1
cosmossdk.io/depinject v1.0.0-alpha.3
cosmossdk.io/log v0.1.0
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d
cosmossdk.io/math v1.0.0
cosmossdk.io/store v0.1.0-alpha.1.0.20230328185921-37ba88872dbc
cosmossdk.io/tools/confix v0.0.0-20230120150717-4f6f6c00021f

View File

@ -198,8 +198,8 @@ cosmossdk.io/depinject v1.0.0-alpha.3 h1:6evFIgj//Y3w09bqOUOzEpFj5tsxBqdc5CfkO7z
cosmossdk.io/depinject v1.0.0-alpha.3/go.mod h1:eRbcdQ7MRpIPEM5YUJh8k97nxHpYbc3sMUnEtt8HPWU=
cosmossdk.io/errors v1.0.0-beta.7 h1:gypHW76pTQGVnHKo6QBkb4yFOJjC+sUGRc5Al3Odj1w=
cosmossdk.io/errors v1.0.0-beta.7/go.mod h1:mz6FQMJRku4bY7aqS/Gwfcmr/ue91roMEKAmDUDpBfE=
cosmossdk.io/log v0.1.0 h1:Vnexi+KzUCjmqq/m93teAxjt5biWFfZ5PI1imx2IJw8=
cosmossdk.io/log v0.1.0/go.mod h1:p95Wq6mDY3SREMc4y7+QU9Uwy3nyvfpWGD1iSaFkVFs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d h1:vRbhjJNv2/GuzU9/PX61Nl/+uyy3gmd5DKoNkQpMzSs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d/go.mod h1:CwX9BLiBruZb7lzLlRr3R231d/fVPUXk8gAdV4LQap0=
cosmossdk.io/math v1.0.0 h1:ro9w7eKx23om2tZz/VM2Pf+z2WAbGX1yDQQOJ6iGeJw=
cosmossdk.io/math v1.0.0/go.mod h1:Ygz4wBHrgc7g0N+8+MrnTfS9LLn9aaTGa9hKopuym5k=
cosmossdk.io/x/tx v0.5.0 h1:01wPSoiYDHlfudV0fn867SBXI3uI/8tpatBgVVSnFzI=

View File

@ -6,7 +6,7 @@ require (
cosmossdk.io/api v0.3.2-0.20230313131911-55bf5d4efbe7
cosmossdk.io/depinject v1.0.0-alpha.3
cosmossdk.io/errors v1.0.0-beta.7
cosmossdk.io/log v0.1.0
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d
cosmossdk.io/math v1.0.0
cosmossdk.io/simapp v0.0.0-20230309163709-87da587416ba
cosmossdk.io/store v0.1.0-alpha.1.0.20230328185921-37ba88872dbc

View File

@ -200,8 +200,8 @@ cosmossdk.io/depinject v1.0.0-alpha.3 h1:6evFIgj//Y3w09bqOUOzEpFj5tsxBqdc5CfkO7z
cosmossdk.io/depinject v1.0.0-alpha.3/go.mod h1:eRbcdQ7MRpIPEM5YUJh8k97nxHpYbc3sMUnEtt8HPWU=
cosmossdk.io/errors v1.0.0-beta.7 h1:gypHW76pTQGVnHKo6QBkb4yFOJjC+sUGRc5Al3Odj1w=
cosmossdk.io/errors v1.0.0-beta.7/go.mod h1:mz6FQMJRku4bY7aqS/Gwfcmr/ue91roMEKAmDUDpBfE=
cosmossdk.io/log v0.1.0 h1:Vnexi+KzUCjmqq/m93teAxjt5biWFfZ5PI1imx2IJw8=
cosmossdk.io/log v0.1.0/go.mod h1:p95Wq6mDY3SREMc4y7+QU9Uwy3nyvfpWGD1iSaFkVFs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d h1:vRbhjJNv2/GuzU9/PX61Nl/+uyy3gmd5DKoNkQpMzSs=
cosmossdk.io/log v0.1.1-0.20230329182155-367f0dc1194d/go.mod h1:CwX9BLiBruZb7lzLlRr3R231d/fVPUXk8gAdV4LQap0=
cosmossdk.io/math v1.0.0 h1:ro9w7eKx23om2tZz/VM2Pf+z2WAbGX1yDQQOJ6iGeJw=
cosmossdk.io/math v1.0.0/go.mod h1:Ygz4wBHrgc7g0N+8+MrnTfS9LLn9aaTGa9hKopuym5k=
cosmossdk.io/x/tx v0.5.0 h1:01wPSoiYDHlfudV0fn867SBXI3uI/8tpatBgVVSnFzI=

View File

@ -9,7 +9,7 @@ import (
)
func main() {
logger := log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "cosmovisor")
logger := log.NewLogger(os.Stdout).With(log.ModuleKey, "cosmovisor")
ctx := context.WithValue(context.Background(), log.ContextKey, logger)
if err := NewRootCmd().ExecuteContext(ctx); err != nil {

View File

@ -112,7 +112,7 @@ func (s *processTestSuite) TestLaunchProcessWithDownloads() {
require := s.Require()
home := copyTestData(s.T(), "download")
cfg := &cosmovisor.Config{Home: home, Name: "autod", AllowDownloadBinaries: true, PollInterval: 100, UnsafeSkipBackup: true}
logger := log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "cosmovisor")
logger := log.NewLogger(os.Stdout).With(log.ModuleKey, "cosmovisor")
upgradeFilename := cfg.UpgradeInfoFilePath()
// should run the genesis binary and produce expected output

View File

@ -95,7 +95,7 @@ func (s *upgradeTestSuite) assertCurrentLink(cfg cosmovisor.Config, target strin
func (s *upgradeTestSuite) TestUpgradeBinaryNoDownloadUrl() {
home := copyTestData(s.T(), "validate")
cfg := &cosmovisor.Config{Home: home, Name: "dummyd", AllowDownloadBinaries: true}
logger := log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "cosmovisor").Impl().(*zerolog.Logger)
logger := log.NewLogger(os.Stdout).With(log.ModuleKey, "cosmovisor").Impl().(*zerolog.Logger)
currentBin, err := cfg.CurrentBin()
s.Require().NoError(err)
@ -128,7 +128,7 @@ func (s *upgradeTestSuite) TestUpgradeBinaryNoDownloadUrl() {
}
func (s *upgradeTestSuite) TestUpgradeBinary() {
logger := log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "cosmovisor").Impl().(*zerolog.Logger)
logger := log.NewLogger(os.Stdout).With(log.ModuleKey, "cosmovisor").Impl().(*zerolog.Logger)
cases := map[string]struct {
url string

View File

@ -11,7 +11,7 @@ import (
func main() {
var (
logger = log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "rosetta")
logger = log.NewLogger(os.Stdout).With(log.ModuleKey, "rosetta")
interfaceRegistry = codectypes.NewInterfaceRegistry()
cdc = codec.NewProtoCodec(interfaceRegistry)
)

View File

@ -61,7 +61,7 @@ func NewServer(settings Settings) (Server, error) {
return Server{}, fmt.Errorf("cannot build asserter: %w", err)
}
logger := log.NewLoggerWithKV(os.Stdout, log.ModuleKey, "rosetta")
logger := log.NewLogger(os.Stdout).With(log.ModuleKey, "rosetta")
var adapter crgtypes.API
switch settings.Offline {