diff --git a/cmd/tendermint/commands/root.go b/cmd/tendermint/commands/root.go index fdee638bc..fd7cebf54 100644 --- a/cmd/tendermint/commands/root.go +++ b/cmd/tendermint/commands/root.go @@ -51,7 +51,8 @@ func RootCommand(conf *config.Config, logger log.Logger) *cobra.Command { } *conf = *pconf config.EnsureRoot(conf.RootDir) - if err := log.OverrideWithNewLogger(logger, conf.LogFormat, conf.LogLevel); err != nil { + logger, err = cli.ParseLogLevel(conf.LogLevel, logger, config.DefaultPackageLogLevels()) + if err != nil { return err } if warning := pconf.DeprecatedFieldWarning(); warning != nil { diff --git a/cmd/tendermint/commands/root_test.go b/cmd/tendermint/commands/root_test.go index 54f96f907..ddc6e99a9 100644 --- a/cmd/tendermint/commands/root_test.go +++ b/cmd/tendermint/commands/root_test.go @@ -135,7 +135,7 @@ func TestRootConfig(t *testing.T) { defer cancel() // write non-default config - nonDefaultLogLvl := "debug" + nonDefaultLogLvl := "abc:debug" cvals := map[string]string{ "log-level": nonDefaultLogLvl, } @@ -145,9 +145,9 @@ func TestRootConfig(t *testing.T) { env map[string]string logLvl string }{ - {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 + {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 } for i, tc := range cases { diff --git a/cmd/tendermint/main.go b/cmd/tendermint/main.go index 1be614aea..6216f97d6 100644 --- a/cmd/tendermint/main.go +++ b/cmd/tendermint/main.go @@ -20,7 +20,7 @@ func main() { panic(err) } - logger, err := log.NewDefaultLogger(conf.LogFormat, conf.LogLevel) + logger, err := log.NewDefaultLogger(conf.LogFormat, "info") // todo incorrect if err != nil { panic(err) } diff --git a/config/config.go b/config/config.go index d875b8569..606fb2388 100644 --- a/config/config.go +++ b/config/config.go @@ -22,9 +22,6 @@ const ( // FuzzModeDelay is a mode in which we randomly sleep FuzzModeDelay - // DefaultLogLevel defines a default log level as INFO. - DefaultLogLevel = "info" - ModeFull = "full" ModeValidator = "validator" ModeSeed = "seed" @@ -236,7 +233,7 @@ func DefaultBaseConfig() BaseConfig { Moniker: defaultMoniker, ProxyApp: "tcp://127.0.0.1:26658", ABCI: "socket", - LogLevel: DefaultLogLevel, + LogLevel: DefaultPackageLogLevels(), LogFormat: log.LogFormatPlain, FilterPeers: false, DBBackend: "goleveldb", @@ -308,6 +305,17 @@ func (cfg BaseConfig) DBDir() string { return rootify(cfg.DBPath, cfg.RootDir) } +// DefaultLogLevel returns a default log level of "error" +func DefaultLogLevel() string { + return "error" +} + +// DefaultPackageLogLevels returns a default log level setting so all packages +// log at "error", while the `state` and `main` packages log at "info" +func DefaultPackageLogLevels() string { + return fmt.Sprintf("main:info,state:info,*:%s", DefaultLogLevel()) +} + // ValidateBasic performs basic validation (checking param bounds, etc.) and // returns an error if any check fails. func (cfg BaseConfig) ValidateBasic() error { diff --git a/libs/cli/log_level.go b/libs/cli/log_level.go new file mode 100644 index 000000000..e133a06e6 --- /dev/null +++ b/libs/cli/log_level.go @@ -0,0 +1,91 @@ +package cli + +import ( + "fmt" + "strings" + + "github.com/pkg/errors" + + "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, errors.Wrap(err, fmt.Sprintf("Failed to parse default log level (pair %s, list %s)", item, l)) + } + 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) + } + fmt.Println(options) + 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/log_level_test.go b/libs/cli/log_level_test.go new file mode 100644 index 000000000..3049b6c23 --- /dev/null +++ b/libs/cli/log_level_test.go @@ -0,0 +1,94 @@ +package cli_test + +import ( + "bytes" + "strings" + "testing" + + tmflags "github.com/tendermint/tendermint/libs/cli" + "github.com/tendermint/tendermint/libs/log" +) + +const ( + defaultLogLevelValue = "info" +) + +func TestParseLogLevel(t *testing.T) { + var buf bytes.Buffer + jsonLogger := log.NewWriterLogger(&buf) + + correctLogLevels := []struct { + lvl string + expectedLogLines []string + }{ + {"mempool:error", []string{ + ``, // if no default is given, assume info + ``, + `{"level":"error","module":"mempool","message":"Mesmero"}`, + `{"level":"info","module":"state","message":"Mind"}`, // if no default is given, assume info + ``}}, + + {"mempool:error,*:debug", []string{ + `{"level":"debug","module":"mempool","module":"wire","message":"Kingpin"}`, + ``, + `{"level":"error","module":"mempool","message":"Mesmero"}`, + `{"level":"info","module":"state","message":"Mind"}`, + `{"level":"debug","message":"Gideon"}`}}, + + {"*:debug,wire:none", []string{ + ``, + `{"level":"info","module":"mempool","message":"Kitty Pryde"}`, + `{"level":"error","module":"mempool","message":"Mesmero"}`, + `{"level":"info","module":"state","message":"Mind"}`, + `{"level":"debug","message":"Gideon"}`}}, + } + + 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/node/node.go b/node/node.go index 1bda1f0f7..56bb83456 100644 --- a/node/node.go +++ b/node/node.go @@ -348,7 +348,7 @@ func makeNode( } if cfg.P2P.PexReactor { - node.services = append(node.services, pex.NewReactor(logger, peerManager, node.router.OpenChannel, peerManager.Subscribe)) + node.services = append(node.services, pex.NewReactor(logger.With("module", "p2p"), peerManager, node.router.OpenChannel, peerManager.Subscribe)) } // Set up state sync reactor, and schedule a sync if requested.