diff --git a/CHANGELOG_PENDING.md b/CHANGELOG_PENDING.md index a675a86ec..29cb54d20 100644 --- a/CHANGELOG_PENDING.md +++ b/CHANGELOG_PENDING.md @@ -32,6 +32,8 @@ Friendly reminder: We have a [bug bounty program](https://hackerone.com/tendermi - P2P Protocol - Go API + - [logging] \#6534 Removed the existing custom Tendermint logger backed by go-kit. The logging interface, `Logger`, remains. + Tendermint still provides a default logger backed by the performant zerolog logger. (@alexanderbez) - [mempool] \#6529 The `Context` field has been removed from the `TxInfo` type. `CheckTx` now requires a `Context` argument. (@alexanderbez) - [abci/client, proxy] \#5673 `Async` funcs return an error, `Sync` and `Async` funcs accept `context.Context` (@melekes) - [p2p] Removed unused function `MakePoWTarget`. (@erikgrinaker) diff --git a/abci/cmd/abci-cli/abci-cli.go b/abci/cmd/abci-cli/abci-cli.go index e5c9c7fec..3f23beb87 100644 --- a/abci/cmd/abci-cli/abci-cli.go +++ b/abci/cmd/abci-cli/abci-cli.go @@ -68,12 +68,9 @@ var RootCmd = &cobra.Command{ } if logger == nil { - allowLevel, err := log.AllowLevel(flagLogLevel) - if err != nil { - return err - } - logger = log.NewFilter(log.NewTMLogger(log.NewSyncWriter(os.Stdout)), allowLevel) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) } + if client == nil { var err error client, err = abcicli.NewClient(flagAddress, flagAbci, false) @@ -598,7 +595,7 @@ func cmdQuery(cmd *cobra.Command, args []string) error { func cmdCounter(cmd *cobra.Command, args []string) error { app := counter.NewApplication(flagSerial) - logger := log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger := log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) // Start the listener srv, err := server.NewServer(flagAddress, flagAbci, app) @@ -623,7 +620,7 @@ func cmdCounter(cmd *cobra.Command, args []string) error { } func cmdKVStore(cmd *cobra.Command, args []string) error { - logger := log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger := log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) // Create the application - in memory or persisted to disk var app types.Application diff --git a/abci/tests/test_app/app.go b/abci/tests/test_app/app.go index b3878fb0d..faf4885de 100644 --- a/abci/tests/test_app/app.go +++ b/abci/tests/test_app/app.go @@ -4,7 +4,6 @@ import ( "bytes" "context" "fmt" - "os" abcicli "github.com/tendermint/tendermint/abci/client" "github.com/tendermint/tendermint/abci/types" @@ -19,7 +18,7 @@ func startClient(abciType string) abcicli.Client { if err != nil { panic(err.Error()) } - logger := log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger := log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) client.SetLogger(logger.With("module", "abcicli")) if err := client.Start(); err != nil { panicf("connecting to abci_app: %v", err.Error()) diff --git a/cmd/priv_val_server/main.go b/cmd/priv_val_server/main.go index ca7b5d62f..203b3df0d 100644 --- a/cmd/priv_val_server/main.go +++ b/cmd/priv_val_server/main.go @@ -46,9 +46,8 @@ func main() { rootCA = flag.String("rootcafile", "", "absolute path to root CA") prometheusAddr = flag.String("prometheus-addr", "", "address for prometheus endpoint (host:port)") - logger = log.NewTMLogger( - log.NewSyncWriter(os.Stdout), - ).With("module", "priv_val") + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false). + With("module", "priv_val") ) flag.Parse() diff --git a/cmd/tendermint/commands/debug/debug.go b/cmd/tendermint/commands/debug/debug.go index 414b2b874..e07f7978d 100644 --- a/cmd/tendermint/commands/debug/debug.go +++ b/cmd/tendermint/commands/debug/debug.go @@ -1,8 +1,6 @@ package debug import ( - "os" - "github.com/spf13/cobra" "github.com/tendermint/tendermint/libs/log" @@ -17,7 +15,7 @@ var ( flagProfAddr = "pprof-laddr" flagFrequency = "frequency" - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) ) // DebugCmd defines the root command containing subcommands that assist in diff --git a/cmd/tendermint/commands/light.go b/cmd/tendermint/commands/light.go index 8c3fef1b7..5e7446e51 100644 --- a/cmd/tendermint/commands/light.go +++ b/cmd/tendermint/commands/light.go @@ -66,7 +66,8 @@ var ( trustedHash []byte trustLevelStr string - verbose bool + logLevel string + logFormat string primaryKey = []byte("primary") witnessesKey = []byte("witnesses") @@ -90,7 +91,8 @@ func init() { "trusting period that headers can be verified within. Should be significantly less than the unbonding period") LightCmd.Flags().Int64Var(&trustedHeight, "height", 1, "Trusted header's height") LightCmd.Flags().BytesHexVar(&trustedHash, "hash", []byte{}, "Trusted header's hash") - LightCmd.Flags().BoolVar(&verbose, "verbose", false, "Verbose output") + LightCmd.Flags().StringVar(&logLevel, "log-level", log.LogLevelInfo, "The logging level (debug|info|warn|error|fatal)") + LightCmd.Flags().StringVar(&logFormat, "log-format", log.LogFormatPlain, "The logging format (text|json)") LightCmd.Flags().StringVar(&trustLevelStr, "trust-level", "1/3", "trust level. Must be between 1/3 and 3/3", ) @@ -100,15 +102,10 @@ func init() { } func runProxy(cmd *cobra.Command, args []string) error { - // Initialize logger. - logger := log.NewTMLogger(log.NewSyncWriter(os.Stdout)) - var option log.Option - if verbose { - option, _ = log.AllowLevel("debug") - } else { - option, _ = log.AllowLevel("info") + logger, err := log.NewDefaultLogger(logFormat, logLevel, false) + if err != nil { + return err } - logger = log.NewFilter(logger, option) chainID = args[0] logger.Info("Creating client...", "chainID", chainID) diff --git a/cmd/tendermint/commands/root.go b/cmd/tendermint/commands/root.go index 7d25cdbff..02f260de5 100644 --- a/cmd/tendermint/commands/root.go +++ b/cmd/tendermint/commands/root.go @@ -2,7 +2,6 @@ package commands import ( "fmt" - "os" "strings" "time" @@ -10,14 +9,12 @@ import ( "github.com/spf13/viper" cfg "github.com/tendermint/tendermint/config" - "github.com/tendermint/tendermint/libs/cli" - tmflags "github.com/tendermint/tendermint/libs/cli/flags" "github.com/tendermint/tendermint/libs/log" ) var ( config = cfg.DefaultConfig() - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) ctxTimeout = 4 * time.Second ) @@ -59,19 +56,11 @@ var RootCmd = &cobra.Command{ return err } - if config.LogFormat == cfg.LogFormatJSON { - logger = log.NewTMJSONLogger(log.NewSyncWriter(os.Stdout)) - } - - logger, err = tmflags.ParseLogLevel(config.LogLevel, logger, cfg.DefaultLogLevel) + logger, err = log.NewDefaultLogger(config.LogFormat, config.LogLevel, false) if err != nil { return err } - if viper.GetBool(cli.TraceFlag) { - logger = log.NewTracingLogger(logger) - } - logger = logger.With("module", "main") return nil }, diff --git a/cmd/tendermint/commands/root_test.go b/cmd/tendermint/commands/root_test.go index 2814435d0..385da7051 100644 --- a/cmd/tendermint/commands/root_test.go +++ b/cmd/tendermint/commands/root_test.go @@ -118,7 +118,7 @@ func TestRootFlagsEnv(t *testing.T) { func TestRootConfig(t *testing.T) { // write non-default config - nonDefaultLogLvl := "abc:debug" + nonDefaultLogLvl := "debug" cvals := map[string]string{ "log-level": nonDefaultLogLvl, } @@ -129,9 +129,9 @@ func TestRootConfig(t *testing.T) { logLvl string }{ - {nil, nil, nonDefaultLogLvl}, // should load config - {[]string{"--log-level=abc:info"}, nil, "abc:info"}, // flag over rides - {nil, map[string]string{"TM_LOG_LEVEL": "abc:info"}, "abc:info"}, // env over rides + {nil, nil, nonDefaultLogLvl}, // should load config + {[]string{"--log-level=info"}, nil, "info"}, // flag over rides + {nil, map[string]string{"TM_LOG_LEVEL": "info"}, "info"}, // env over rides } for i, tc := range cases { diff --git a/config/config.go b/config/config.go index 8cb3c75d0..843b8ec18 100644 --- a/config/config.go +++ b/config/config.go @@ -8,6 +8,8 @@ import ( "os" "path/filepath" "time" + + "github.com/tendermint/tendermint/libs/log" ) const ( @@ -16,11 +18,6 @@ const ( // FuzzModeDelay is a mode in which we randomly sleep FuzzModeDelay - // LogFormatPlain is a format for colored text - LogFormatPlain = "plain" - // LogFormatJSON is a format for json output - LogFormatJSON = "json" - // DefaultLogLevel defines a default log level as INFO. DefaultLogLevel = "info" @@ -276,7 +273,7 @@ func DefaultBaseConfig() BaseConfig { ProxyApp: "tcp://127.0.0.1:26658", ABCI: "socket", LogLevel: DefaultLogLevel, - LogFormat: LogFormatPlain, + LogFormat: log.LogFormatPlain, FastSyncMode: true, FilterPeers: false, DBBackend: "goleveldb", @@ -331,17 +328,20 @@ func (cfg Config) ArePrivValidatorClientSecurityOptionsPresent() bool { // returns an error if any check fails. func (cfg BaseConfig) ValidateBasic() error { switch cfg.LogFormat { - case LogFormatPlain, LogFormatJSON: + case log.LogFormatJSON, log.LogFormatText, log.LogFormatPlain: default: - return errors.New("unknown log format (must be 'plain' or 'json')") + return errors.New("unknown log format (must be 'plain', 'text' or 'json')") } + switch cfg.Mode { case ModeFull, ModeValidator, ModeSeed: case "": return errors.New("no mode has been set") + default: return fmt.Errorf("unknown mode: %v", cfg.Mode) } + return nil } diff --git a/consensus/common_test.go b/consensus/common_test.go index 803a22757..52f4dc3fe 100644 --- a/consensus/common_test.go +++ b/consensus/common_test.go @@ -12,7 +12,6 @@ import ( "testing" "time" - "github.com/go-kit/kit/log/term" "github.com/stretchr/testify/require" "path" @@ -690,14 +689,7 @@ func ensureNewEventOnChannel(ch <-chan tmpubsub.Message) { // consensusLogger is a TestingLogger which uses a different // color for each validator ("validator" key must exist). func consensusLogger() log.Logger { - return log.TestingLoggerWithColorFn(func(keyvals ...interface{}) term.FgBgColor { - for i := 0; i < len(keyvals)-1; i += 2 { - if keyvals[i] == "validator" { - return term.FgBgColor{Fg: term.Color(uint8(keyvals[i+1].(int) + 1))} - } - } - return term.FgBgColor{} - }).With("module", "consensus") + return log.TestingLogger().With("module", "consensus") } func randConsensusState( diff --git a/go.mod b/go.mod index 3cdacac6d..8797ab029 100644 --- a/go.mod +++ b/go.mod @@ -31,6 +31,7 @@ require ( github.com/prometheus/client_golang v1.10.0 github.com/rcrowley/go-metrics v0.0.0-20200313005456-10cdbea86bc0 github.com/rs/cors v1.7.0 + github.com/rs/zerolog v1.22.0 github.com/sasha-s/go-deadlock v0.2.1-0.20190427202633-1595213edefa github.com/snikch/goodman v0.0.0-20171125024755-10e37e294daa github.com/spf13/cobra v1.1.3 diff --git a/go.sum b/go.sum index aef8ba832..62117f216 100644 --- a/go.sum +++ b/go.sum @@ -472,6 +472,9 @@ github.com/rogpeppe/fastuuid v1.2.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6L github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= github.com/rs/cors v1.7.0 h1:+88SsELBHx5r+hZ8TCkggzSstaWNbDvThkVK8H6f9ik= github.com/rs/cors v1.7.0/go.mod h1:gFx+x8UowdsKA9AchylcLynDq+nNFfI8FkUZdN/jGCU= +github.com/rs/xid v1.2.1/go.mod h1:+uKXf+4Djp6Md1KODXJxgGQPKngRmWyn10oCKFzNHOQ= +github.com/rs/zerolog v1.22.0 h1:XrVUjV4K+izZpKXZHlPrYQiDtmdGiCylnT4i43AAWxg= +github.com/rs/zerolog v1.22.0/go.mod h1:ZPhntP/xmq1nnND05hhpAh2QMhSsA4UN3MGZ6O2J3hM= github.com/russross/blackfriday v1.5.2/go.mod h1:JO/DiYxRf+HjHt06OyowR9PTA263kcR/rfWxYHBV53g= github.com/russross/blackfriday/v2 v2.0.1/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts= @@ -695,6 +698,7 @@ golang.org/x/sys v0.0.0-20200625212154-ddb9806d33ae/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20200814200057-3d37ad5750ed/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20201015000850-e3ed0017c211/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210309074719-68d13333faf2 h1:46ULzRKLh1CwgRq2dC5SlBzEqqNCi8rreOZnNrbqcIY= golang.org/x/sys v0.0.0-20210309074719-68d13333faf2/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= @@ -736,6 +740,7 @@ golang.org/x/tools v0.0.0-20200207183749-b753a1ba74fa/go.mod h1:TB2adYChydJhpapK golang.org/x/tools v0.0.0-20200619180055-7c47624df98f/go.mod h1:EkVYQZoAsY45+roYkvgYkIh4xh/qjgUK9TdY2XT94GE= golang.org/x/tools v0.0.0-20201022035929-9cf592e881e9/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA= golang.org/x/tools v0.0.0-20210106214847-113979e3529a/go.mod h1:emZCQorbCU4vsT4fOWvOPXz4eW1wZW4PmDk9uLelYpA= +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= diff --git a/libs/cli/flags/log_level.go b/libs/cli/flags/log_level.go deleted file mode 100644 index d96ad3f47..000000000 --- a/libs/cli/flags/log_level.go +++ /dev/null @@ -1,89 +0,0 @@ -package flags - -import ( - "errors" - "fmt" - "strings" - - "github.com/tendermint/tendermint/libs/log" -) - -const ( - defaultLogLevelKey = "*" -) - -// ParseLogLevel parses complex log level - comma-separated -// list of module:level pairs with an optional *:level pair (* means -// all other modules). -// -// Example: -// ParseLogLevel("consensus:debug,mempool:debug,*:error", log.NewTMLogger(os.Stdout), "info") -func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) (log.Logger, error) { - if lvl == "" { - return nil, errors.New("empty log level") - } - - l := lvl - - // prefix simple one word levels (e.g. "info") with "*" - if !strings.Contains(l, ":") { - l = defaultLogLevelKey + ":" + l - } - - options := make([]log.Option, 0) - - isDefaultLogLevelSet := false - var option log.Option - var err error - - 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 module == defaultLogLevelKey { - option, err = log.AllowLevel(level) - if err != nil { - return nil, fmt.Errorf("failed to parse default log level (pair %s, list %s): %w", item, l, err) - } - options = append(options, option) - isDefaultLogLevelSet = true - } else { - switch level { - case "debug": - option = log.AllowDebugWith("module", module) - case "info": - option = log.AllowInfoWith("module", module) - case "error": - option = log.AllowErrorWith("module", module) - case "none": - option = log.AllowNoneWith("module", module) - default: - return nil, - fmt.Errorf("expected either \"info\", \"debug\", \"error\" or \"none\" log level, given %s (pair %s, list %s)", - level, - item, - list) - } - options = append(options, option) - - } - } - - // if "*" is not provided, set default global level - if !isDefaultLogLevelSet { - option, err = log.AllowLevel(defaultLogLevelValue) - if err != nil { - return nil, err - } - options = append(options, option) - } - - return log.NewFilter(logger, options...), nil -} diff --git a/libs/cli/flags/log_level_test.go b/libs/cli/flags/log_level_test.go deleted file mode 100644 index 9d1b24009..000000000 --- a/libs/cli/flags/log_level_test.go +++ /dev/null @@ -1,94 +0,0 @@ -package flags_test - -import ( - "bytes" - "strings" - "testing" - - tmflags "github.com/tendermint/tendermint/libs/cli/flags" - "github.com/tendermint/tendermint/libs/log" -) - -const ( - defaultLogLevelValue = "info" -) - -func TestParseLogLevel(t *testing.T) { - var buf bytes.Buffer - jsonLogger := log.NewTMJSONLoggerNoTS(&buf) - - correctLogLevels := []struct { - lvl string - expectedLogLines []string - }{ - {"mempool:error", []string{ - ``, // if no default is given, assume info - ``, - `{"_msg":"Mesmero","level":"error","module":"mempool"}`, - `{"_msg":"Mind","level":"info","module":"state"}`, // if no default is given, assume info - ``}}, - - {"mempool:error,*:debug", []string{ - `{"_msg":"Kingpin","level":"debug","module":"wire"}`, - ``, - `{"_msg":"Mesmero","level":"error","module":"mempool"}`, - `{"_msg":"Mind","level":"info","module":"state"}`, - `{"_msg":"Gideon","level":"debug"}`}}, - - {"*:debug,wire:none", []string{ - ``, - `{"_msg":"Kitty Pryde","level":"info","module":"mempool"}`, - `{"_msg":"Mesmero","level":"error","module":"mempool"}`, - `{"_msg":"Mind","level":"info","module":"state"}`, - `{"_msg":"Gideon","level":"debug"}`}}, - } - - for _, c := range correctLogLevels { - logger, err := tmflags.ParseLogLevel(c.lvl, jsonLogger, defaultLogLevelValue) - if err != nil { - t.Fatal(err) - } - - buf.Reset() - - logger.With("module", "mempool").With("module", "wire").Debug("Kingpin") - if have := strings.TrimSpace(buf.String()); c.expectedLogLines[0] != have { - t.Errorf("\nwant '%s'\nhave '%s'\nlevel '%s'", c.expectedLogLines[0], have, c.lvl) - } - - buf.Reset() - - logger.With("module", "mempool").Info("Kitty Pryde") - if have := strings.TrimSpace(buf.String()); c.expectedLogLines[1] != have { - t.Errorf("\nwant '%s'\nhave '%s'\nlevel '%s'", c.expectedLogLines[1], have, c.lvl) - } - - buf.Reset() - - logger.With("module", "mempool").Error("Mesmero") - if have := strings.TrimSpace(buf.String()); c.expectedLogLines[2] != have { - t.Errorf("\nwant '%s'\nhave '%s'\nlevel '%s'", c.expectedLogLines[2], have, c.lvl) - } - - buf.Reset() - - logger.With("module", "state").Info("Mind") - if have := strings.TrimSpace(buf.String()); c.expectedLogLines[3] != have { - t.Errorf("\nwant '%s'\nhave '%s'\nlevel '%s'", c.expectedLogLines[3], have, c.lvl) - } - - buf.Reset() - - logger.Debug("Gideon") - if have := strings.TrimSpace(buf.String()); c.expectedLogLines[4] != have { - t.Errorf("\nwant '%s'\nhave '%s'\nlevel '%s'", c.expectedLogLines[4], have, c.lvl) - } - } - - incorrectLogLevel := []string{"some", "mempool:some", "*:some,mempool:error"} - for _, lvl := range incorrectLogLevel { - if _, err := tmflags.ParseLogLevel(lvl, jsonLogger, defaultLogLevelValue); err == nil { - t.Fatalf("Expected %s to produce error", lvl) - } - } -} diff --git a/libs/log/default.go b/libs/log/default.go new file mode 100644 index 000000000..249a0689c --- /dev/null +++ b/libs/log/default.go @@ -0,0 +1,101 @@ +package log + +import ( + "fmt" + "io" + "os" + "strings" + + "github.com/rs/zerolog" +) + +var _ Logger = (*defaultLogger)(nil) + +type defaultLogger struct { + zerolog.Logger + + trace bool +} + +// NewDefaultLogger returns a default logger that can be used within Tendermint +// and that fulfills the Logger interface. The underlying logging provider is a +// zerolog logger that supports typical log levels along with JSON and plain/text +// log formats. +// +// Since zerolog supports typed structured logging and it is difficult to reflect +// that in a generic interface, all logging methods accept a series of key/value +// pair tuples, where the key must be a string. +func NewDefaultLogger(format, level string, trace bool) (Logger, error) { + var logWriter io.Writer + switch strings.ToLower(format) { + case LogFormatPlain, LogFormatText: + logWriter = zerolog.ConsoleWriter{Out: os.Stderr} + + case LogFormatJSON: + logWriter = os.Stderr + + default: + return nil, fmt.Errorf("unsupported log format: %s", format) + } + + logLevel, err := zerolog.ParseLevel(level) + if err != nil { + return nil, fmt.Errorf("failed to parse log level (%s): %w", level, err) + } + + // make the writer thread-safe + logWriter = newSyncWriter(logWriter) + + return defaultLogger{ + Logger: zerolog.New(logWriter).Level(logLevel).With().Timestamp().Logger(), + trace: trace, + }, nil +} + +// MustNewDefaultLogger delegates a call NewDefaultLogger where it panics on +// error. +func MustNewDefaultLogger(format, level string, trace bool) Logger { + logger, err := NewDefaultLogger(format, level, trace) + if err != nil { + panic(err) + } + + return logger +} + +func (l defaultLogger) Info(msg string, keyVals ...interface{}) { + l.Logger.Info().Fields(getLogFields(keyVals...)).Msg(msg) +} + +func (l defaultLogger) Error(msg string, keyVals ...interface{}) { + e := l.Logger.Error() + if l.trace { + e = e.Stack() + } + + e.Fields(getLogFields(keyVals...)).Msg(msg) +} + +func (l defaultLogger) Debug(msg string, keyVals ...interface{}) { + l.Logger.Debug().Fields(getLogFields(keyVals...)).Msg(msg) +} + +func (l defaultLogger) With(keyVals ...interface{}) Logger { + return defaultLogger{ + Logger: l.Logger.With().Fields(getLogFields(keyVals...)).Logger(), + trace: l.trace, + } +} + +func getLogFields(keyVals ...interface{}) map[string]interface{} { + if len(keyVals)%2 != 0 { + return nil + } + + fields := make(map[string]interface{}, len(keyVals)) + for i := 0; i < len(keyVals); i += 2 { + fields[fmt.Sprint(keyVals[i])] = keyVals[i+1] + } + + return fields +} diff --git a/libs/log/default_test.go b/libs/log/default_test.go new file mode 100644 index 000000000..c66508f04 --- /dev/null +++ b/libs/log/default_test.go @@ -0,0 +1,48 @@ +package log_test + +import ( + "testing" + + "github.com/stretchr/testify/require" + "github.com/tendermint/tendermint/libs/log" +) + +func TestNewDefaultLogger(t *testing.T) { + testCases := map[string]struct { + format string + level string + expectErr bool + }{ + "invalid format": { + format: "foo", + level: log.LogLevelInfo, + expectErr: true, + }, + "invalid level": { + format: log.LogFormatJSON, + level: "foo", + expectErr: true, + }, + "valid format and level": { + format: log.LogFormatJSON, + level: log.LogLevelInfo, + expectErr: false, + }, + } + + for name, tc := range testCases { + tc := tc + + t.Run(name, func(t *testing.T) { + _, err := log.NewDefaultLogger(tc.format, tc.level, false) + if tc.expectErr { + require.Error(t, err) + require.Panics(t, func() { + _ = log.MustNewDefaultLogger(tc.format, tc.level, false) + }) + } else { + require.NoError(t, err) + } + }) + } +} diff --git a/libs/log/filter.go b/libs/log/filter.go deleted file mode 100644 index e39a85dcb..000000000 --- a/libs/log/filter.go +++ /dev/null @@ -1,195 +0,0 @@ -package log - -import "fmt" - -type level byte - -const ( - levelDebug level = 1 << iota - levelInfo - levelError -) - -type filter struct { - next Logger - allowed level // XOR'd levels for default case - initiallyAllowed level // XOR'd levels for initial case - allowedKeyvals map[keyval]level // When key-value match, use this level -} - -type keyval struct { - key interface{} - value interface{} -} - -// NewFilter wraps next and implements filtering. See the commentary on the -// Option functions for a detailed description of how to configure levels. If -// no options are provided, all leveled log events created with Debug, Info or -// Error helper methods are squelched. -func NewFilter(next Logger, options ...Option) Logger { - l := &filter{ - next: next, - allowedKeyvals: make(map[keyval]level), - } - for _, option := range options { - option(l) - } - l.initiallyAllowed = l.allowed - return l -} - -func (l *filter) Info(msg string, keyvals ...interface{}) { - levelAllowed := l.allowed&levelInfo != 0 - if !levelAllowed { - return - } - l.next.Info(msg, keyvals...) -} - -func (l *filter) Debug(msg string, keyvals ...interface{}) { - levelAllowed := l.allowed&levelDebug != 0 - if !levelAllowed { - return - } - l.next.Debug(msg, keyvals...) -} - -func (l *filter) Error(msg string, keyvals ...interface{}) { - levelAllowed := l.allowed&levelError != 0 - if !levelAllowed { - return - } - l.next.Error(msg, keyvals...) -} - -// With implements Logger by constructing a new filter with a keyvals appended -// to the logger. -// -// If custom level was set for a keyval pair using one of the -// Allow*With methods, it is used as the logger's level. -// -// Examples: -// logger = log.NewFilter(logger, log.AllowError(), log.AllowInfoWith("module", "crypto")) -// logger.With("module", "crypto").Info("Hello") # produces "I... Hello module=crypto" -// -// logger = log.NewFilter(logger, log.AllowError(), -// log.AllowInfoWith("module", "crypto"), -// log.AllowNoneWith("user", "Sam")) -// logger.With("module", "crypto", "user", "Sam").Info("Hello") # returns nil -// -// logger = log.NewFilter(logger, -// log.AllowError(), -// log.AllowInfoWith("module", "crypto"), log.AllowNoneWith("user", "Sam")) -// logger.With("user", "Sam").With("module", "crypto").Info("Hello") # produces "I... Hello module=crypto user=Sam" -func (l *filter) With(keyvals ...interface{}) Logger { - keyInAllowedKeyvals := false - - for i := len(keyvals) - 2; i >= 0; i -= 2 { - for kv, allowed := range l.allowedKeyvals { - if keyvals[i] == kv.key { - keyInAllowedKeyvals = true - // Example: - // logger = log.NewFilter(logger, log.AllowError(), log.AllowInfoWith("module", "crypto")) - // logger.With("module", "crypto") - if keyvals[i+1] == kv.value { - return &filter{ - next: l.next.With(keyvals...), - allowed: allowed, // set the desired level - allowedKeyvals: l.allowedKeyvals, - initiallyAllowed: l.initiallyAllowed, - } - } - } - } - } - - // Example: - // logger = log.NewFilter(logger, log.AllowError(), log.AllowInfoWith("module", "crypto")) - // logger.With("module", "main") - if keyInAllowedKeyvals { - return &filter{ - next: l.next.With(keyvals...), - allowed: l.initiallyAllowed, // return back to initially allowed - allowedKeyvals: l.allowedKeyvals, - initiallyAllowed: l.initiallyAllowed, - } - } - - return &filter{ - next: l.next.With(keyvals...), - allowed: l.allowed, // simply continue with the current level - allowedKeyvals: l.allowedKeyvals, - initiallyAllowed: l.initiallyAllowed, - } -} - -//-------------------------------------------------------------------------------- - -// Option sets a parameter for the filter. -type Option func(*filter) - -// AllowLevel returns an option for the given level or error if no option exist -// for such level. -func AllowLevel(lvl string) (Option, error) { - switch lvl { - case "debug": - return AllowDebug(), nil - case "info": - return AllowInfo(), nil - case "error": - return AllowError(), nil - case "none": - return AllowNone(), nil - default: - return nil, fmt.Errorf("expected either \"info\", \"debug\", \"error\" or \"none\" level, given %s", lvl) - } -} - -// AllowAll is an alias for AllowDebug. -func AllowAll() Option { - return AllowDebug() -} - -// AllowDebug allows error, info and debug level log events to pass. -func AllowDebug() Option { - return allowed(levelError | levelInfo | levelDebug) -} - -// AllowInfo allows error and info level log events to pass. -func AllowInfo() Option { - return allowed(levelError | levelInfo) -} - -// AllowError allows only error level log events to pass. -func AllowError() Option { - return allowed(levelError) -} - -// AllowNone allows no leveled log events to pass. -func AllowNone() Option { - return allowed(0) -} - -func allowed(allowed level) Option { - return func(l *filter) { l.allowed = allowed } -} - -// AllowDebugWith allows error, info and debug level log events to pass for a specific key value pair. -func AllowDebugWith(key interface{}, value interface{}) Option { - return func(l *filter) { l.allowedKeyvals[keyval{key, value}] = levelError | levelInfo | levelDebug } -} - -// AllowInfoWith allows error and info level log events to pass for a specific key value pair. -func AllowInfoWith(key interface{}, value interface{}) Option { - return func(l *filter) { l.allowedKeyvals[keyval{key, value}] = levelError | levelInfo } -} - -// AllowErrorWith allows only error level log events to pass for a specific key value pair. -func AllowErrorWith(key interface{}, value interface{}) Option { - return func(l *filter) { l.allowedKeyvals[keyval{key, value}] = levelError } -} - -// AllowNoneWith allows no leveled log events to pass for a specific key value pair. -func AllowNoneWith(key interface{}, value interface{}) Option { - return func(l *filter) { l.allowedKeyvals[keyval{key, value}] = 0 } -} diff --git a/libs/log/filter_test.go b/libs/log/filter_test.go deleted file mode 100644 index b2ba18394..000000000 --- a/libs/log/filter_test.go +++ /dev/null @@ -1,140 +0,0 @@ -package log_test - -import ( - "bytes" - "strings" - "testing" - - "github.com/tendermint/tendermint/libs/log" -) - -func TestVariousLevels(t *testing.T) { - testCases := []struct { - name string - allowed log.Option - want string - }{ - { - "AllowAll", - log.AllowAll(), - strings.Join([]string{ - `{"_msg":"here","level":"debug","this is":"debug log"}`, - `{"_msg":"here","level":"info","this is":"info log"}`, - `{"_msg":"here","level":"error","this is":"error log"}`, - }, "\n"), - }, - { - "AllowDebug", - log.AllowDebug(), - strings.Join([]string{ - `{"_msg":"here","level":"debug","this is":"debug log"}`, - `{"_msg":"here","level":"info","this is":"info log"}`, - `{"_msg":"here","level":"error","this is":"error log"}`, - }, "\n"), - }, - { - "AllowInfo", - log.AllowInfo(), - strings.Join([]string{ - `{"_msg":"here","level":"info","this is":"info log"}`, - `{"_msg":"here","level":"error","this is":"error log"}`, - }, "\n"), - }, - { - "AllowError", - log.AllowError(), - strings.Join([]string{ - `{"_msg":"here","level":"error","this is":"error log"}`, - }, "\n"), - }, - { - "AllowNone", - log.AllowNone(), - ``, - }, - } - - for _, tc := range testCases { - tc := tc - t.Run(tc.name, func(t *testing.T) { - var buf bytes.Buffer - logger := log.NewFilter(log.NewTMJSONLoggerNoTS(&buf), tc.allowed) - - logger.Debug("here", "this is", "debug log") - logger.Info("here", "this is", "info log") - logger.Error("here", "this is", "error log") - - if want, have := tc.want, strings.TrimSpace(buf.String()); want != have { - t.Errorf("\nwant:\n%s\nhave:\n%s", want, have) - } - }) - } -} - -func TestLevelContext(t *testing.T) { - var buf bytes.Buffer - - logger := log.NewTMJSONLoggerNoTS(&buf) - logger = log.NewFilter(logger, log.AllowError()) - logger = logger.With("context", "value") - - logger.Error("foo", "bar", "baz") - - want := `{"_msg":"foo","bar":"baz","context":"value","level":"error"}` - have := strings.TrimSpace(buf.String()) - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } - - buf.Reset() - logger.Info("foo", "bar", "baz") - if want, have := ``, strings.TrimSpace(buf.String()); want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } -} - -func TestVariousAllowWith(t *testing.T) { - var buf bytes.Buffer - - logger := log.NewTMJSONLoggerNoTS(&buf) - - logger1 := log.NewFilter(logger, log.AllowError(), log.AllowInfoWith("context", "value")) - logger1.With("context", "value").Info("foo", "bar", "baz") - - want := `{"_msg":"foo","bar":"baz","context":"value","level":"info"}` - have := strings.TrimSpace(buf.String()) - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } - - buf.Reset() - - logger2 := log.NewFilter( - logger, - log.AllowError(), - log.AllowInfoWith("context", "value"), - log.AllowNoneWith("user", "Sam"), - ) - - logger2.With("context", "value", "user", "Sam").Info("foo", "bar", "baz") - if want, have := ``, strings.TrimSpace(buf.String()); want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } - - buf.Reset() - - logger3 := log.NewFilter( - logger, - log.AllowError(), - log.AllowInfoWith("context", "value"), - log.AllowNoneWith("user", "Sam"), - ) - - logger3.With("user", "Sam").With("context", "value").Info("foo", "bar", "baz") - - want = `{"_msg":"foo","bar":"baz","context":"value","level":"info","user":"Sam"}` - have = strings.TrimSpace(buf.String()) - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } -} diff --git a/libs/log/logger.go b/libs/log/logger.go index ddb187bc7..b96081870 100644 --- a/libs/log/logger.go +++ b/libs/log/logger.go @@ -2,29 +2,56 @@ package log import ( "io" + "sync" +) + +const ( + // LogFormatPlain defines a logging format used for human-readable text-based + // logging that is not structured. Typically, this format is used for development + // and testing purposes. + LogFormatPlain string = "plain" + + // LogFormatText defines a logging format used for human-readable text-based + // logging that is not structured. Typically, this format is used for development + // and testing purposes. + LogFormatText string = "text" + + // LogFormatJSON defines a logging format for structured JSON-based logging + // that is typically used in production environments, which can be sent to + // logging facilities that support complex log parsing and querying. + LogFormatJSON string = "json" - kitlog "github.com/go-kit/kit/log" + // Supported loging levels + LogLevelDebug = "debug" + LogLevelInfo = "info" + LogLevelWarn = "warn" + LogLevelError = "error" ) -// Logger is what any Tendermint library should take. +// Logger defines a generic logging interface compatible with Tendermint. type Logger interface { - Debug(msg string, keyvals ...interface{}) - Info(msg string, keyvals ...interface{}) - Error(msg string, keyvals ...interface{}) + Debug(msg string, keyVals ...interface{}) + Info(msg string, keyVals ...interface{}) + Error(msg string, keyVals ...interface{}) + + With(keyVals ...interface{}) Logger +} + +// syncWriter wraps an io.Writer that can be used in a Logger that is safe for +// concurrent use by multiple goroutines. +type syncWriter struct { + sync.Mutex + io.Writer +} - With(keyvals ...interface{}) Logger +func newSyncWriter(w io.Writer) io.Writer { + return &syncWriter{Writer: w} } -// NewSyncWriter returns a new writer that is safe for concurrent use by -// multiple goroutines. Writes to the returned writer are passed on to w. If -// another write is already in progress, the calling goroutine blocks until -// the writer is available. -// -// If w implements the following interface, so does the returned writer. -// -// interface { -// Fd() uintptr -// } -func NewSyncWriter(w io.Writer) io.Writer { - return kitlog.NewSyncWriter(w) +// Write writes p to the underlying io.Writer. If another write is already in +// progress, the calling goroutine blocks until the syncWriter is available. +func (w *syncWriter) Write(p []byte) (int, error) { + w.Lock() + defer w.Unlock() + return w.Writer.Write(p) } diff --git a/libs/log/nop.go b/libs/log/nop.go new file mode 100644 index 000000000..4b3bfb196 --- /dev/null +++ b/libs/log/nop.go @@ -0,0 +1,12 @@ +package log + +import ( + "github.com/rs/zerolog" +) + +func NewNopLogger() Logger { + return defaultLogger{ + Logger: zerolog.Nop(), + trace: false, + } +} diff --git a/libs/log/nop_logger.go b/libs/log/nop_logger.go deleted file mode 100644 index 12d75abe6..000000000 --- a/libs/log/nop_logger.go +++ /dev/null @@ -1,17 +0,0 @@ -package log - -type nopLogger struct{} - -// Interface assertions -var _ Logger = (*nopLogger)(nil) - -// NewNopLogger returns a logger that doesn't do anything. -func NewNopLogger() Logger { return &nopLogger{} } - -func (nopLogger) Info(string, ...interface{}) {} -func (nopLogger) Debug(string, ...interface{}) {} -func (nopLogger) Error(string, ...interface{}) {} - -func (l *nopLogger) With(...interface{}) Logger { - return l -} diff --git a/libs/log/testing.go b/libs/log/testing.go new file mode 100644 index 000000000..9894f6a50 --- /dev/null +++ b/libs/log/testing.go @@ -0,0 +1,41 @@ +package log + +import ( + "io" + "os" + "sync" + "testing" +) + +var ( + // reuse the same logger across all tests + testingLoggerMtx = sync.Mutex{} + testingLogger Logger +) + +// TestingLogger returns a Logger which writes to STDOUT if test(s) are being +// run with the verbose (-v) flag, NopLogger otherwise. +// +// NOTE: +// - A call to NewTestingLogger() must be made inside a test (not in the init func) +// because verbose flag only set at the time of testing. +func TestingLogger() Logger { + return TestingLoggerWithOutput(os.Stdout) +} + +func TestingLoggerWithOutput(w io.Writer) Logger { + testingLoggerMtx.Lock() + defer testingLoggerMtx.Unlock() + + if testingLogger != nil { + return testingLogger + } + + if testing.Verbose() { + testingLogger = MustNewDefaultLogger(LogFormatText, LogLevelDebug, true) + } else { + testingLogger = NewNopLogger() + } + + return testingLogger +} diff --git a/libs/log/testing_logger.go b/libs/log/testing_logger.go deleted file mode 100644 index 95a7e3f7c..000000000 --- a/libs/log/testing_logger.go +++ /dev/null @@ -1,66 +0,0 @@ -package log - -import ( - "io" - "os" - "sync" - "testing" - - "github.com/go-kit/kit/log/term" -) - -var ( - // reuse the same logger across all tests - _testingLoggerMutex = sync.Mutex{} - _testingLogger Logger -) - -// TestingLogger returns a TMLogger which writes to STDOUT if testing being run -// with the verbose (-v) flag, NopLogger otherwise. -// -// Note that the call to TestingLogger() must be made -// inside a test (not in the init func) because -// verbose flag only set at the time of testing. -func TestingLogger() Logger { - return TestingLoggerWithOutput(os.Stdout) -} - -// TestingLoggerWOutput returns a TMLogger which writes to (w io.Writer) if testing being run -// with the verbose (-v) flag, NopLogger otherwise. -// -// Note that the call to TestingLoggerWithOutput(w io.Writer) must be made -// inside a test (not in the init func) because -// verbose flag only set at the time of testing. -func TestingLoggerWithOutput(w io.Writer) Logger { - _testingLoggerMutex.Lock() - defer _testingLoggerMutex.Unlock() - if _testingLogger != nil { - return _testingLogger - } - - if testing.Verbose() { - _testingLogger = NewTMLogger(NewSyncWriter(w)) - } else { - _testingLogger = NewNopLogger() - } - - return _testingLogger -} - -// TestingLoggerWithColorFn allow you to provide your own color function. See -// TestingLogger for documentation. -func TestingLoggerWithColorFn(colorFn func(keyvals ...interface{}) term.FgBgColor) Logger { - _testingLoggerMutex.Lock() - defer _testingLoggerMutex.Unlock() - if _testingLogger != nil { - return _testingLogger - } - - if testing.Verbose() { - _testingLogger = NewTMLoggerWithColorFn(NewSyncWriter(os.Stdout), colorFn) - } else { - _testingLogger = NewNopLogger() - } - - return _testingLogger -} diff --git a/libs/log/tm_json_logger.go b/libs/log/tm_json_logger.go deleted file mode 100644 index 3ebeddaa3..000000000 --- a/libs/log/tm_json_logger.go +++ /dev/null @@ -1,24 +0,0 @@ -package log - -import ( - "io" - - kitlog "github.com/go-kit/kit/log" -) - -// NewTMJSONLogger returns a Logger that encodes keyvals to the Writer as a -// single JSON object. Each log event produces no more than one call to -// w.Write. The passed Writer must be safe for concurrent use by multiple -// goroutines if the returned Logger will be used concurrently. -func NewTMJSONLogger(w io.Writer) Logger { - logger := kitlog.NewJSONLogger(w) - logger = kitlog.With(logger, "ts", kitlog.DefaultTimestampUTC) - return &tmLogger{logger} -} - -// NewTMJSONLoggerNoTS is the same as NewTMJSONLogger, but without the -// timestamp. -func NewTMJSONLoggerNoTS(w io.Writer) Logger { - logger := kitlog.NewJSONLogger(w) - return &tmLogger{logger} -} diff --git a/libs/log/tm_logger.go b/libs/log/tm_logger.go deleted file mode 100644 index 7c106336c..000000000 --- a/libs/log/tm_logger.go +++ /dev/null @@ -1,86 +0,0 @@ -package log - -import ( - "fmt" - "io" - - kitlog "github.com/go-kit/kit/log" - kitlevel "github.com/go-kit/kit/log/level" - "github.com/go-kit/kit/log/term" -) - -const ( - msgKey = "_msg" // "_" prefixed to avoid collisions - moduleKey = "module" -) - -type tmLogger struct { - srcLogger kitlog.Logger -} - -// Interface assertions -var _ Logger = (*tmLogger)(nil) - -// NewTMLogger returns a logger that encodes msg and keyvals to the Writer -// using go-kit's log as an underlying logger and our custom formatter. Note -// that underlying logger could be swapped with something else. -func NewTMLogger(w io.Writer) Logger { - // Color by level value - colorFn := func(keyvals ...interface{}) term.FgBgColor { - if keyvals[0] != kitlevel.Key() { - panic(fmt.Sprintf("expected level key to be first, got %v", keyvals[0])) - } - switch keyvals[1].(kitlevel.Value).String() { - case "debug": - return term.FgBgColor{Fg: term.DarkGray} - case "error": - return term.FgBgColor{Fg: term.Red} - default: - return term.FgBgColor{} - } - } - - return &tmLogger{term.NewLogger(w, NewTMFmtLogger, colorFn)} -} - -// NewTMLoggerWithColorFn allows you to provide your own color function. See -// NewTMLogger for documentation. -func NewTMLoggerWithColorFn(w io.Writer, colorFn func(keyvals ...interface{}) term.FgBgColor) Logger { - return &tmLogger{term.NewLogger(w, NewTMFmtLogger, colorFn)} -} - -// Info logs a message at level Info. -func (l *tmLogger) Info(msg string, keyvals ...interface{}) { - lWithLevel := kitlevel.Info(l.srcLogger) - - if err := kitlog.With(lWithLevel, msgKey, msg).Log(keyvals...); err != nil { - errLogger := kitlevel.Error(l.srcLogger) - kitlog.With(errLogger, msgKey, msg).Log("err", err) //nolint:errcheck // no need to check error again - } -} - -// Debug logs a message at level Debug. -func (l *tmLogger) Debug(msg string, keyvals ...interface{}) { - lWithLevel := kitlevel.Debug(l.srcLogger) - - if err := kitlog.With(lWithLevel, msgKey, msg).Log(keyvals...); err != nil { - errLogger := kitlevel.Error(l.srcLogger) - kitlog.With(errLogger, msgKey, msg).Log("err", err) //nolint:errcheck // no need to check error again - } -} - -// Error logs a message at level Error. -func (l *tmLogger) Error(msg string, keyvals ...interface{}) { - lWithLevel := kitlevel.Error(l.srcLogger) - - lWithMsg := kitlog.With(lWithLevel, msgKey, msg) - if err := lWithMsg.Log(keyvals...); err != nil { - lWithMsg.Log("err", err) //nolint:errcheck // no need to check error again - } -} - -// With returns a new contextual logger with keyvals prepended to those passed -// to calls to Info, Debug or Error. -func (l *tmLogger) With(keyvals ...interface{}) Logger { - return &tmLogger{kitlog.With(l.srcLogger, keyvals...)} -} diff --git a/libs/log/tm_logger_test.go b/libs/log/tm_logger_test.go deleted file mode 100644 index cbe29d994..000000000 --- a/libs/log/tm_logger_test.go +++ /dev/null @@ -1,112 +0,0 @@ -package log_test - -import ( - "bytes" - "io/ioutil" - "strings" - "testing" - - "github.com/tendermint/tendermint/libs/log" -) - -func TestLoggerLogsItsErrors(t *testing.T) { - var buf bytes.Buffer - - logger := log.NewTMLogger(&buf) - logger.Info("foo", "baz baz", "bar") - msg := strings.TrimSpace(buf.String()) - if !strings.Contains(msg, "foo") { - t.Errorf("expected logger msg to contain ErrInvalidKey, got %s", msg) - } -} - -func TestInfo(t *testing.T) { - var bufInfo bytes.Buffer - - l := log.NewTMLogger(&bufInfo) - l.Info("Client initialized with old header (trusted is more recent)", - "old", 42, - "trustedHeight", "forty two", - "trustedHash", []byte("test me")) - - msg := strings.TrimSpace(bufInfo.String()) - - // Remove the timestamp information to allow - // us to test against the expected message. - receivedmsg := strings.Split(msg, "] ")[1] - - const expectedmsg = `Client initialized with old header - (trusted is more recent) old=42 trustedHeight="forty two" - trustedHash=74657374206D65` - if strings.EqualFold(receivedmsg, expectedmsg) { - t.Fatalf("received %s, expected %s", receivedmsg, expectedmsg) - } -} - -func TestDebug(t *testing.T) { - var bufDebug bytes.Buffer - - ld := log.NewTMLogger(&bufDebug) - ld.Debug("Client initialized with old header (trusted is more recent)", - "old", 42, - "trustedHeight", "forty two", - "trustedHash", []byte("test me")) - - msg := strings.TrimSpace(bufDebug.String()) - - // Remove the timestamp information to allow - // us to test against the expected message. - receivedmsg := strings.Split(msg, "] ")[1] - - const expectedmsg = `Client initialized with old header - (trusted is more recent) old=42 trustedHeight="forty two" - trustedHash=74657374206D65` - if strings.EqualFold(receivedmsg, expectedmsg) { - t.Fatalf("received %s, expected %s", receivedmsg, expectedmsg) - } -} - -func TestError(t *testing.T) { - var bufErr bytes.Buffer - - le := log.NewTMLogger(&bufErr) - le.Error("Client initialized with old header (trusted is more recent)", - "old", 42, - "trustedHeight", "forty two", - "trustedHash", []byte("test me")) - - msg := strings.TrimSpace(bufErr.String()) - - // Remove the timestamp information to allow - // us to test against the expected message. - receivedmsg := strings.Split(msg, "] ")[1] - - const expectedmsg = `Client initialized with old header - (trusted is more recent) old=42 trustedHeight="forty two" - trustedHash=74657374206D65` - if strings.EqualFold(receivedmsg, expectedmsg) { - t.Fatalf("received %s, expected %s", receivedmsg, expectedmsg) - } -} - -func BenchmarkTMLoggerSimple(b *testing.B) { - benchmarkRunner(b, log.NewTMLogger(ioutil.Discard), baseInfoMessage) -} - -func BenchmarkTMLoggerContextual(b *testing.B) { - benchmarkRunner(b, log.NewTMLogger(ioutil.Discard), withInfoMessage) -} - -func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) { - lc := logger.With("common_key", "common_value") - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - f(lc) - } -} - -var ( - baseInfoMessage = func(logger log.Logger) { logger.Info("foo_message", "foo_key", "foo_value") } - withInfoMessage = func(logger log.Logger) { logger.With("a", "b").Info("c", "d", "f") } -) diff --git a/libs/log/tmfmt_logger.go b/libs/log/tmfmt_logger.go deleted file mode 100644 index b9389b18e..000000000 --- a/libs/log/tmfmt_logger.go +++ /dev/null @@ -1,135 +0,0 @@ -package log - -import ( - "bytes" - "encoding/hex" - "fmt" - "io" - "strings" - "sync" - "time" - - kitlog "github.com/go-kit/kit/log" - kitlevel "github.com/go-kit/kit/log/level" - "github.com/go-logfmt/logfmt" -) - -type tmfmtEncoder struct { - *logfmt.Encoder - buf bytes.Buffer -} - -func (l *tmfmtEncoder) Reset() { - l.Encoder.Reset() - l.buf.Reset() -} - -var tmfmtEncoderPool = sync.Pool{ - New: func() interface{} { - var enc tmfmtEncoder - enc.Encoder = logfmt.NewEncoder(&enc.buf) - return &enc - }, -} - -type tmfmtLogger struct { - w io.Writer -} - -// NewTMFmtLogger returns a logger that encodes keyvals to the Writer in -// Tendermint custom format. Note complex types (structs, maps, slices) -// formatted as "%+v". -// -// Each log event produces no more than one call to w.Write. -// The passed Writer must be safe for concurrent use by multiple goroutines if -// the returned Logger will be used concurrently. -func NewTMFmtLogger(w io.Writer) kitlog.Logger { - return &tmfmtLogger{w} -} - -func (l tmfmtLogger) Log(keyvals ...interface{}) error { - enc := tmfmtEncoderPool.Get().(*tmfmtEncoder) - enc.Reset() - defer tmfmtEncoderPool.Put(enc) - - const unknown = "unknown" - lvl := "none" - msg := unknown - module := unknown - - // indexes of keys to skip while encoding later - excludeIndexes := make([]int, 0) - - for i := 0; i < len(keyvals)-1; i += 2 { - // Extract level - switch keyvals[i] { - case kitlevel.Key(): - excludeIndexes = append(excludeIndexes, i) - switch keyvals[i+1].(type) { // nolint:gocritic - case string: - lvl = keyvals[i+1].(string) - case kitlevel.Value: - lvl = keyvals[i+1].(kitlevel.Value).String() - default: - panic(fmt.Sprintf("level value of unknown type %T", keyvals[i+1])) - } - // and message - case msgKey: - excludeIndexes = append(excludeIndexes, i) - msg = keyvals[i+1].(string) - // and module (could be multiple keyvals; if such case last keyvalue wins) - case moduleKey: - excludeIndexes = append(excludeIndexes, i) - module = keyvals[i+1].(string) - } - - // Print []byte as a hexadecimal string (uppercased) - if b, ok := keyvals[i+1].([]byte); ok { - keyvals[i+1] = strings.ToUpper(hex.EncodeToString(b)) - } - } - - // Form a custom Tendermint line - // - // Example: - // D[2016-05-02|11:06:44.322] Stopping AddrBook (ignoring: already stopped) - // - // Description: - // D - first character of the level, uppercase (ASCII only) - // [2016-05-02|11:06:44.322] - our time format (see https://golang.org/src/time/format.go) - // Stopping ... - message - fmt.Fprintf(&enc.buf, "%c[%s] %-44s ", lvl[0]-32, time.Now().Format("2006-01-02|15:04:05.000"), msg) - - if module != unknown { - enc.buf.WriteString("module=" + module + " ") - } - -KeyvalueLoop: - for i := 0; i < len(keyvals)-1; i += 2 { - for _, j := range excludeIndexes { - if i == j { - continue KeyvalueLoop - } - } - - err := enc.EncodeKeyval(keyvals[i], keyvals[i+1]) - if err == logfmt.ErrUnsupportedValueType { - enc.EncodeKeyval(keyvals[i], fmt.Sprintf("%+v", keyvals[i+1])) //nolint:errcheck // no need to check error again - } else if err != nil { - return err - } - } - - // Add newline to the end of the buffer - if err := enc.EndRecord(); err != nil { - return err - } - - // The Logger interface requires implementations to be safe for concurrent - // use by multiple goroutines. For this implementation that means making - // only one call to l.w.Write() for each call to Log. - if _, err := l.w.Write(enc.buf.Bytes()); err != nil { - return err - } - return nil -} diff --git a/libs/log/tmfmt_logger_test.go b/libs/log/tmfmt_logger_test.go deleted file mode 100644 index 955a9e405..000000000 --- a/libs/log/tmfmt_logger_test.go +++ /dev/null @@ -1,126 +0,0 @@ -package log_test - -import ( - "bytes" - "errors" - "io/ioutil" - "math" - "regexp" - "testing" - - kitlog "github.com/go-kit/kit/log" - "github.com/stretchr/testify/assert" - - "github.com/tendermint/tendermint/libs/log" -) - -func TestTMFmtLogger(t *testing.T) { - t.Parallel() - buf := &bytes.Buffer{} - logger := log.NewTMFmtLogger(buf) - - if err := logger.Log("hello", "world"); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+ hello=world\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("a", 1, "err", errors.New("error")); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+ a=1 err=error\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("std_map", map[int]int{1: 2}, "my_map", mymap{0: 0}); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+ std_map=map\[1:2\] my_map=special_behavior\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("level", "error"); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`E\[.+\] unknown \s+\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("_msg", "Hello"); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] Hello \s+\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("module", "main", "module", "crypto", "module", "wire"); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+module=wire\s+\n$`), buf.String()) - - buf.Reset() - if err := logger.Log("hash", []byte("test me")); err != nil { - t.Fatal(err) - } - assert.Regexp(t, regexp.MustCompile(`N\[.+\] unknown \s+ hash=74657374206D65\n$`), buf.String()) -} - -func BenchmarkTMFmtLoggerSimple(b *testing.B) { - benchmarkRunnerKitlog(b, log.NewTMFmtLogger(ioutil.Discard), baseMessage) -} - -func BenchmarkTMFmtLoggerContextual(b *testing.B) { - benchmarkRunnerKitlog(b, log.NewTMFmtLogger(ioutil.Discard), withMessage) -} - -func TestTMFmtLoggerConcurrency(t *testing.T) { - t.Parallel() - testConcurrency(t, log.NewTMFmtLogger(ioutil.Discard), 10000) -} - -func benchmarkRunnerKitlog(b *testing.B, logger kitlog.Logger, f func(kitlog.Logger)) { - lc := kitlog.With(logger, "common_key", "common_value") - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - f(lc) - } -} - -//nolint: errcheck // ignore errors -var ( - baseMessage = func(logger kitlog.Logger) { logger.Log("foo_key", "foo_value") } - withMessage = func(logger kitlog.Logger) { kitlog.With(logger, "a", "b").Log("d", "f") } -) - -// These test are designed to be run with the race detector. - -func testConcurrency(t *testing.T, logger kitlog.Logger, total int) { - n := int(math.Sqrt(float64(total))) - share := total / n - - errC := make(chan error, n) - - for i := 0; i < n; i++ { - go func() { - errC <- spam(logger, share) - }() - } - - for i := 0; i < n; i++ { - err := <-errC - if err != nil { - t.Fatalf("concurrent logging error: %v", err) - } - } -} - -func spam(logger kitlog.Logger, count int) error { - for i := 0; i < count; i++ { - err := logger.Log("key", i) - if err != nil { - return err - } - } - return nil -} - -type mymap map[int]int - -func (m mymap) String() string { return "special_behavior" } diff --git a/libs/log/tracing_logger.go b/libs/log/tracing_logger.go deleted file mode 100644 index d2a6ff44e..000000000 --- a/libs/log/tracing_logger.go +++ /dev/null @@ -1,76 +0,0 @@ -package log - -import ( - "fmt" - - "github.com/pkg/errors" -) - -// NewTracingLogger enables tracing by wrapping all errors (if they -// implement stackTracer interface) in tracedError. -// -// All errors returned by https://github.com/pkg/errors implement stackTracer -// interface. -// -// For debugging purposes only as it doubles the amount of allocations. -func NewTracingLogger(next Logger) Logger { - return &tracingLogger{ - next: next, - } -} - -type stackTracer interface { - error - StackTrace() errors.StackTrace -} - -type tracingLogger struct { - next Logger -} - -func (l *tracingLogger) Info(msg string, keyvals ...interface{}) { - l.next.Info(msg, formatErrors(keyvals)...) -} - -func (l *tracingLogger) Debug(msg string, keyvals ...interface{}) { - l.next.Debug(msg, formatErrors(keyvals)...) -} - -func (l *tracingLogger) Error(msg string, keyvals ...interface{}) { - l.next.Error(msg, formatErrors(keyvals)...) -} - -func (l *tracingLogger) With(keyvals ...interface{}) Logger { - return &tracingLogger{next: l.next.With(formatErrors(keyvals)...)} -} - -func formatErrors(keyvals []interface{}) []interface{} { - newKeyvals := make([]interface{}, len(keyvals)) - copy(newKeyvals, keyvals) - for i := 0; i < len(newKeyvals)-1; i += 2 { - if err, ok := newKeyvals[i+1].(stackTracer); ok { - newKeyvals[i+1] = tracedError{err} - } - } - return newKeyvals -} - -// tracedError wraps a stackTracer and just makes the Error() result -// always return a full stack trace. -type tracedError struct { - wrapped stackTracer -} - -var _ stackTracer = tracedError{} - -func (t tracedError) StackTrace() errors.StackTrace { - return t.wrapped.StackTrace() -} - -func (t tracedError) Cause() error { - return t.wrapped -} - -func (t tracedError) Error() string { - return fmt.Sprintf("%+v", t.wrapped) -} diff --git a/libs/log/tracing_logger_test.go b/libs/log/tracing_logger_test.go deleted file mode 100644 index f32ac9c57..000000000 --- a/libs/log/tracing_logger_test.go +++ /dev/null @@ -1,65 +0,0 @@ -package log_test - -import ( - "bytes" - stderr "errors" - "fmt" - "strings" - "testing" - - "github.com/pkg/errors" - - "github.com/tendermint/tendermint/libs/log" -) - -func TestTracingLogger(t *testing.T) { - var buf bytes.Buffer - - logger := log.NewTMJSONLoggerNoTS(&buf) - - logger1 := log.NewTracingLogger(logger) - err1 := errors.New("courage is grace under pressure") - err2 := errors.New("it does not matter how slowly you go, so long as you do not stop") - logger1.With("err1", err1).Info("foo", "err2", err2) - - want := strings.ReplaceAll( - strings.ReplaceAll( - `{"_msg":"foo","err1":"`+ - fmt.Sprintf("%+v", err1)+ - `","err2":"`+ - fmt.Sprintf("%+v", err2)+ - `","level":"info"}`, - "\t", "", - ), "\n", "") - have := strings.ReplaceAll(strings.ReplaceAll(strings.TrimSpace(buf.String()), "\\n", ""), "\\t", "") - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } - - buf.Reset() - - logger.With( - "err1", stderr.New("opportunities don't happen. You create them"), - ).Info( - "foo", "err2", stderr.New("once you choose hope, anything's possible"), - ) - - want = `{"_msg":"foo",` + - `"err1":"opportunities don't happen. You create them",` + - `"err2":"once you choose hope, anything's possible",` + - `"level":"info"}` - have = strings.TrimSpace(buf.String()) - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } - - buf.Reset() - - logger.With("user", "Sam").With("context", "value").Info("foo", "bar", "baz") - - want = `{"_msg":"foo","bar":"baz","context":"value","level":"info","user":"Sam"}` - have = strings.TrimSpace(buf.String()) - if want != have { - t.Errorf("\nwant '%s'\nhave '%s'", want, have) - } -} diff --git a/libs/service/service.go b/libs/service/service.go index 8447eae8c..0af243995 100644 --- a/libs/service/service.go +++ b/libs/service/service.go @@ -133,22 +133,22 @@ func (bs *BaseService) SetLogger(l log.Logger) { func (bs *BaseService) Start() error { if atomic.CompareAndSwapUint32(&bs.started, 0, 1) { if atomic.LoadUint32(&bs.stopped) == 1 { - bs.Logger.Error(fmt.Sprintf("Not starting %v service -- already stopped", bs.name), - "impl", bs.impl) - // revert flag + bs.Logger.Error("not starting service; already stopped", "service", bs.name, "impl", bs.impl.String()) atomic.StoreUint32(&bs.started, 0) return ErrAlreadyStopped } - bs.Logger.Info(fmt.Sprintf("Starting %v service", bs.name), "impl", bs.impl.String()) - err := bs.impl.OnStart() - if err != nil { + + bs.Logger.Info("starting service", "service", bs.name, "impl", bs.impl.String()) + + if err := bs.impl.OnStart(); err != nil { // revert flag atomic.StoreUint32(&bs.started, 0) return err } return nil } - bs.Logger.Debug(fmt.Sprintf("Not starting %v service -- already started", bs.name), "impl", bs.impl) + + bs.Logger.Debug("not starting service; already started", "service", bs.name, "impl", bs.impl.String()) return ErrAlreadyStarted } @@ -162,18 +162,19 @@ func (bs *BaseService) OnStart() error { return nil } func (bs *BaseService) Stop() error { if atomic.CompareAndSwapUint32(&bs.stopped, 0, 1) { if atomic.LoadUint32(&bs.started) == 0 { - bs.Logger.Error(fmt.Sprintf("Not stopping %v service -- has not been started yet", bs.name), - "impl", bs.impl) - // revert flag + bs.Logger.Error("not stopping service; not started yet", "service", bs.name, "impl", bs.impl.String()) atomic.StoreUint32(&bs.stopped, 0) return ErrNotStarted } - bs.Logger.Info(fmt.Sprintf("Stopping %v service", bs.name), "impl", bs.impl) + + bs.Logger.Info("stopping service", "service", bs.name, "impl", bs.impl.String()) bs.impl.OnStop() close(bs.quit) + return nil } - bs.Logger.Debug(fmt.Sprintf("Stopping %v service (already stopped)", bs.name), "impl", bs.impl) + + bs.Logger.Debug("not stopping service; already stopped", "service", bs.name, "impl", bs.impl.String()) return ErrAlreadyStopped } @@ -186,7 +187,7 @@ func (bs *BaseService) OnStop() {} // will be returned if the service is running. func (bs *BaseService) Reset() error { if !atomic.CompareAndSwapUint32(&bs.stopped, 1, 0) { - bs.Logger.Debug(fmt.Sprintf("Can't reset %v service. Not stopped", bs.name), "impl", bs.impl) + bs.Logger.Debug("cannot reset service; not stopped", "service", bs.name, "impl", bs.impl.String()) return fmt.Errorf("can't reset running %s", bs.name) } diff --git a/rpc/jsonrpc/jsonrpc_test.go b/rpc/jsonrpc/jsonrpc_test.go index 405610c3d..6e0c03f00 100644 --- a/rpc/jsonrpc/jsonrpc_test.go +++ b/rpc/jsonrpc/jsonrpc_test.go @@ -13,7 +13,6 @@ import ( "testing" "time" - "github.com/go-kit/kit/log/term" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -91,22 +90,9 @@ func TestMain(m *testing.M) { os.Exit(code) } -var colorFn = func(keyvals ...interface{}) term.FgBgColor { - for i := 0; i < len(keyvals)-1; i += 2 { - if keyvals[i] == "socket" { - if keyvals[i+1] == "tcp" { - return term.FgBgColor{Fg: term.DarkBlue} - } else if keyvals[i+1] == "unix" { - return term.FgBgColor{Fg: term.DarkCyan} - } - } - } - return term.FgBgColor{} -} - // launch unix and tcp servers func setup() { - logger := log.NewTMLoggerWithColorFn(log.NewSyncWriter(os.Stdout), colorFn) + logger := log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) cmd := exec.Command("rm", "-f", unixSocket) err := cmd.Start() diff --git a/rpc/jsonrpc/server/http_json_handler_test.go b/rpc/jsonrpc/server/http_json_handler_test.go index 591277586..529f7619c 100644 --- a/rpc/jsonrpc/server/http_json_handler_test.go +++ b/rpc/jsonrpc/server/http_json_handler_test.go @@ -1,7 +1,6 @@ package server import ( - "bytes" "encoding/json" "io/ioutil" "net/http" @@ -22,8 +21,7 @@ func testMux() *http.ServeMux { "block": NewRPCFunc(func(ctx *types.Context, h int) (string, error) { return "block", nil }, "height", true), } mux := http.NewServeMux() - buf := new(bytes.Buffer) - logger := log.NewTMLogger(buf) + logger := log.NewNopLogger() RegisterRPCFuncs(mux, funcMap, logger) return mux diff --git a/rpc/jsonrpc/test/main.go b/rpc/jsonrpc/test/main.go index e36caa3b5..1c949571f 100644 --- a/rpc/jsonrpc/test/main.go +++ b/rpc/jsonrpc/test/main.go @@ -3,7 +3,6 @@ package main import ( "fmt" "net/http" - "os" "github.com/tendermint/tendermint/libs/log" tmos "github.com/tendermint/tendermint/libs/os" @@ -26,7 +25,7 @@ type Result struct { func main() { var ( mux = http.NewServeMux() - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) ) // Stop upon receiving SIGTERM or CTRL-C. diff --git a/rpc/test/helpers.go b/rpc/test/helpers.go index de7b0611e..e85ae12fd 100644 --- a/rpc/test/helpers.go +++ b/rpc/test/helpers.go @@ -113,8 +113,7 @@ func StartTendermint(ctx context.Context, if nodeOpts.suppressStdout { logger = log.NewNopLogger() } else { - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) - logger = log.NewFilter(logger, log.AllowError()) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) } papp := proxy.NewLocalClientCreator(app) node, err := nm.New(conf, logger, papp, nil) diff --git a/store/store_test.go b/store/store_test.go index ba70cd97d..1aea1e5a9 100644 --- a/store/store_test.go +++ b/store/store_test.go @@ -1,7 +1,6 @@ package store import ( - "bytes" "fmt" "os" "runtime/debug" @@ -87,7 +86,7 @@ var ( func TestMain(m *testing.M) { var cleanup cleanupFunc - state, _, cleanup = makeStateAndBlockStore(log.NewTMLogger(new(bytes.Buffer))) + state, _, cleanup = makeStateAndBlockStore(log.NewNopLogger()) block = makeBlock(1, state, new(types.Commit)) partSet = block.MakePartSet(2) part1 = partSet.GetPart(0) @@ -100,7 +99,7 @@ func TestMain(m *testing.M) { // TODO: This test should be simplified ... func TestBlockStoreSaveLoadBlock(t *testing.T) { - state, bs, cleanup := makeStateAndBlockStore(log.NewTMLogger(new(bytes.Buffer))) + state, bs, cleanup := makeStateAndBlockStore(log.NewNopLogger()) defer cleanup() require.Equal(t, bs.Base(), int64(0), "initially the base should be zero") require.Equal(t, bs.Height(), int64(0), "initially the height should be zero") @@ -483,7 +482,7 @@ func TestLoadBlockMeta(t *testing.T) { } func TestBlockFetchAtHeight(t *testing.T) { - state, bs, cleanup := makeStateAndBlockStore(log.NewTMLogger(new(bytes.Buffer))) + state, bs, cleanup := makeStateAndBlockStore(log.NewNopLogger()) defer cleanup() require.Equal(t, bs.Height(), int64(0), "initially the height should be zero") block := makeBlock(bs.Height()+1, state, new(types.Commit)) diff --git a/test/e2e/app/app.go b/test/e2e/app/app.go index 89e0ce296..26b10d32a 100644 --- a/test/e2e/app/app.go +++ b/test/e2e/app/app.go @@ -5,7 +5,6 @@ import ( "encoding/base64" "errors" "fmt" - "os" "path/filepath" "strconv" @@ -39,7 +38,7 @@ func NewApplication(cfg *Config) (*Application, error) { return nil, err } return &Application{ - logger: log.NewTMLogger(log.NewSyncWriter(os.Stdout)), + logger: log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false), state: state, snapshots: snapshots, cfg: cfg, diff --git a/test/e2e/app/main.go b/test/e2e/app/main.go index a4a0c7d8b..68ff63b3f 100644 --- a/test/e2e/app/main.go +++ b/test/e2e/app/main.go @@ -17,7 +17,6 @@ import ( "github.com/tendermint/tendermint/abci/server" "github.com/tendermint/tendermint/config" "github.com/tendermint/tendermint/crypto/ed25519" - tmflags "github.com/tendermint/tendermint/libs/cli/flags" "github.com/tendermint/tendermint/libs/log" tmnet "github.com/tendermint/tendermint/libs/net" "github.com/tendermint/tendermint/light" @@ -34,7 +33,7 @@ import ( e2e "github.com/tendermint/tendermint/test/e2e/pkg" ) -var logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) +var logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) // main is the binary entrypoint. func main() { @@ -287,18 +286,12 @@ func setupNode() (*config.Config, log.Logger, error) { return nil, nil, fmt.Errorf("error in config file: %w", err) } - if tmcfg.LogFormat == config.LogFormatJSON { - logger = log.NewTMJSONLogger(log.NewSyncWriter(os.Stdout)) - } - - nodeLogger, err := tmflags.ParseLogLevel(tmcfg.LogLevel, logger, config.DefaultLogLevel) + nodeLogger, err := log.NewDefaultLogger(tmcfg.LogFormat, tmcfg.LogLevel, false) if err != nil { return nil, nil, err } - nodeLogger = nodeLogger.With("module", "main") - - return tmcfg, nodeLogger, nil + return tmcfg, nodeLogger.With("module", "main"), nil } // rpcEndpoints takes a list of persistent peers and splits them into a list of rpc endpoints diff --git a/test/e2e/generator/main.go b/test/e2e/generator/main.go index 91080c063..f353241fc 100644 --- a/test/e2e/generator/main.go +++ b/test/e2e/generator/main.go @@ -17,7 +17,7 @@ const ( randomSeed int64 = 4827085738 ) -var logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) +var logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) func main() { NewCLI().Run() diff --git a/test/e2e/runner/main.go b/test/e2e/runner/main.go index 38066dac5..18fc6adb7 100644 --- a/test/e2e/runner/main.go +++ b/test/e2e/runner/main.go @@ -13,7 +13,7 @@ import ( ) var ( - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) ) func main() { diff --git a/test/fuzz/p2p/pex/reactor_receive.go b/test/fuzz/p2p/pex/reactor_receive.go index 40e8feb66..70f87cc7e 100644 --- a/test/fuzz/p2p/pex/reactor_receive.go +++ b/test/fuzz/p2p/pex/reactor_receive.go @@ -2,7 +2,6 @@ package pex import ( "net" - "os" "github.com/tendermint/tendermint/config" "github.com/tendermint/tendermint/crypto/ed25519" @@ -16,7 +15,7 @@ import ( var ( pexR *pex.Reactor peer p2p.Peer - logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) ) func init() { diff --git a/test/fuzz/rpc/jsonrpc/server/handler.go b/test/fuzz/rpc/jsonrpc/server/handler.go index b93388dd1..cab1b6ed0 100644 --- a/test/fuzz/rpc/jsonrpc/server/handler.go +++ b/test/fuzz/rpc/jsonrpc/server/handler.go @@ -6,7 +6,6 @@ import ( "io/ioutil" "net/http" "net/http/httptest" - "os" "github.com/tendermint/tendermint/libs/log" rs "github.com/tendermint/tendermint/rpc/jsonrpc/server" @@ -20,7 +19,7 @@ var mux *http.ServeMux func init() { mux = http.NewServeMux() - lgr := log.NewTMLogger(log.NewSyncWriter(os.Stdout)) + lgr := log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) rs.RegisterRPCFuncs(mux, rpcFuncMap, lgr) } diff --git a/tools/tm-signer-harness/main.go b/tools/tm-signer-harness/main.go index a32537fff..a6d1312a1 100644 --- a/tools/tm-signer-harness/main.go +++ b/tools/tm-signer-harness/main.go @@ -25,7 +25,7 @@ const ( var defaultTMHome string -var logger = log.NewTMLogger(log.NewSyncWriter(os.Stdout)) +var logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo, false) // Command line flags var ( @@ -166,8 +166,6 @@ func main() { os.Exit(0) } - logger = log.NewFilter(logger, log.AllowInfo()) - switch rootCmd.Arg(0) { case "help": switch rootCmd.Arg(1) {