diff --git a/cmd/ostracon/commands/root.go b/cmd/ostracon/commands/root.go index c585e6891..0b8dc6054 100644 --- a/cmd/ostracon/commands/root.go +++ b/cmd/ostracon/commands/root.go @@ -10,7 +10,6 @@ import ( cfg "github.com/line/ostracon/config" "github.com/line/ostracon/libs/cli" - tmflags "github.com/line/ostracon/libs/cli/flags" "github.com/line/ostracon/libs/log" ) @@ -61,7 +60,7 @@ var RootCmd = &cobra.Command{ logger = log.NewOCJSONLogger(log.NewSyncWriter(os.Stdout)) } - logger, err = tmflags.ParseLogLevel(config.LogLevel, logger, cfg.DefaultLogLevel) + logger, err = log.ParseLogLevel(config.LogLevel, logger, cfg.DefaultLogLevel) if err != nil { return err } diff --git a/config/config.go b/config/config.go index d02bc4353..7217e567d 100644 --- a/config/config.go +++ b/config/config.go @@ -201,6 +201,27 @@ type BaseConfig struct { //nolint: maligned // Output format: 'plain' (colored text) or 'json' LogFormat string `mapstructure:"log_format"` + // LogPath is the file to write logs to(log dir + log filename) + // ex) /Users/user/.app/logs/app.log + // If left as an empty string, log file writing is disabled. + LogPath string `mapstructure:"log_path"` + + // LogMaxAge is the maximum number of days to retain old log files based on the + // timestamp encoded in their filename. Note that a day is defined as 24 + // hours and may not exactly correspond to calendar days due to daylight + // savings, leap seconds, etc. The default is not to remove old log files + // based on age. + LogMaxAge int `mapstructure:"log_max_age"` + + // LogMaxSize is the maximum size in megabytes of the log file before it gets + // rotated. It defaults to 100 megabytes. + LogMaxSize int `mapstructure:"log_max_size"` + + // LogMaxBackups is the maximum number of old log files to retain. The default + // is to retain all old log files (though MaxAge may still cause them to get + // deleted.) + LogMaxBackups int `mapstructure:"log_max_backups"` + // Path to the JSON file containing the initial validator set and other meta data Genesis string `mapstructure:"genesis_file"` @@ -238,8 +259,12 @@ func DefaultBaseConfig() BaseConfig { Moniker: defaultMoniker, ProxyApp: "tcp://127.0.0.1:26658", ABCI: "socket", - LogLevel: DefaultLogLevel, + LogLevel: DefaultPackageLogLevels(), LogFormat: LogFormatPlain, + LogPath: "", + LogMaxAge: 0, + LogMaxSize: 100, + LogMaxBackups: 0, FastSyncMode: true, FilterPeers: false, DBBackend: DefaultDBBackend, @@ -302,6 +327,12 @@ func (cfg BaseConfig) ValidateBasic() error { return nil } +// 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,statesync:info,*:%s", DefaultLogLevel) +} + //----------------------------------------------------------------------------- // RPCConfig @@ -1108,12 +1139,14 @@ func (cfg *ConsensusConfig) ValidateBasic() error { return nil } -//----------------------------------------------------------------------------- +// ----------------------------------------------------------------------------- // TxIndexConfig // Remember that Event has the following structure: // type: [ -// key: value, -// ... +// +// key: value, +// ... +// // ] // // CompositeKeys are constructed by `type.key` diff --git a/config/toml.go b/config/toml.go index 58573b7de..c2e3dc900 100644 --- a/config/toml.go +++ b/config/toml.go @@ -122,6 +122,27 @@ log_level = "{{ .BaseConfig.LogLevel }}" # Output format: 'plain' (colored text) or 'json' log_format = "{{ .BaseConfig.LogFormat }}" +# LogPath is the file to write logs to(log dir + log filename) +# ex) /Users/user/.app/logs/app.log +# If left as an empty string, log file writing is disabled. +log_path = "{{ .BaseConfig.LogPath }}" + +# LogMaxAge is the maximum number of days to retain old log files based on the +# timestamp encoded in their filename. Note that a day is defined as 24 +# hours and may not exactly correspond to calendar days due to daylight +# savings, leap seconds, etc. The default is not to remove old log files +# based on age. +log_max_age = "{{ .BaseConfig.LogMaxAge }}" + +# LogMaxSize is the maximum size in megabytes of the log file before it gets +# rotated. It defaults to 100 megabytes. +log_max_size = "{{ .BaseConfig.LogMaxSize }}" + +# LogMaxBackups is the maximum number of old log files to retain. The default +# is to retain all old log files (though MaxAge may still cause them to get +# deleted.) +log_max_backups = "{{ .BaseConfig.LogMaxBackups }}" + ##### additional base config options ##### # Path to the JSON file containing the initial validator set and other meta data diff --git a/go.mod b/go.mod index d581a7d82..8969d040d 100644 --- a/go.mod +++ b/go.mod @@ -49,6 +49,11 @@ require ( gotest.tools v2.2.0+incompatible // indirect ) +require ( + github.com/rs/zerolog v1.28.0 + gopkg.in/natefinch/lumberjack.v2 v2.0.0 +) + require ( github.com/Azure/go-ansiterm v0.0.0-20210617225240-d185dfc1b5a1 // indirect github.com/DataDog/zstd v1.4.1 // indirect @@ -75,6 +80,8 @@ require ( github.com/inconshreveable/mousetrap v1.0.1 // indirect github.com/jmhodges/levigo v1.0.0 // indirect github.com/magiconair/properties v1.8.6 // indirect + github.com/mattn/go-colorable v0.1.12 // indirect + github.com/mattn/go-isatty v0.0.14 // indirect github.com/matttproud/golang_protobuf_extensions v1.0.1 // indirect github.com/mimoo/StrobeGo v0.0.0-20181016162300-f8f6d4d2b643 // indirect github.com/mitchellh/mapstructure v1.5.0 // indirect diff --git a/go.sum b/go.sum index dfd5b1d33..bb616bafd 100644 --- a/go.sum +++ b/go.sum @@ -109,6 +109,7 @@ github.com/coreos/etcd v3.3.10+incompatible/go.mod h1:uF7uidLiAD3TWHmW31ZFd/JWoc github.com/coreos/go-etcd v2.0.0+incompatible/go.mod h1:Jez6KQU2B/sWsbdaef3ED8NzMklzPG4d5KIOhIy30Tk= github.com/coreos/go-semver v0.2.0/go.mod h1:nnelYz7RCh+5ahJtPPxZlU+153eP4D4r3EedlOD2RNk= github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= +github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/cosmos/go-bip39 v0.0.0-20180819234021-555e2067c45d h1:49RLWk1j44Xu4fjHb6JFYmeUnDORVwHNkDxaQ0ctCVU= github.com/cosmos/go-bip39 v0.0.0-20180819234021-555e2067c45d/go.mod h1:tSxLoYXyBmiFeKpvmq4dzayMdCjCnu8uqmCysIGBT2Y= github.com/cosmos/gorocksdb v1.2.0 h1:d0l3jJG8M4hBouIZq0mDUHZ+zjOx044J3nGRskwTb4Y= @@ -304,6 +305,10 @@ github.com/libp2p/go-buffer-pool v0.1.0/go.mod h1:N+vh8gMqimBzdKkSMVuydVDq+UV5QT github.com/magiconair/properties v1.8.0/go.mod h1:PppfXfuXeibc/6YijjN8zIbojt8czPbwD3XqdrwzmxQ= github.com/magiconair/properties v1.8.6 h1:5ibWZ6iY0NctNGWo87LalDlEZ6R41TqbbDamhfG/Qzo= github.com/magiconair/properties v1.8.6/go.mod h1:y3VJvCyxH9uVvJTWEGAELF3aiYNyPKd5NZ3oSwXrF60= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/mattn/go-sqlite3 v1.14.9 h1:10HX2Td0ocZpYEjhilsuo6WWtUqttj2Kb0KtD86/KYA= github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU= github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0= @@ -397,6 +402,9 @@ github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFR github.com/rogpeppe/go-internal v1.6.1 h1:/FiVV8dS/e+YqF2JvO3yXRFbBLTIuSDkuC7aBOAvL+k= github.com/rs/cors v1.8.2 h1:KCooALfAYGs415Cwu5ABvv9n9509fSiG5SQJn/AQo4U= github.com/rs/cors v1.8.2/go.mod h1:XyqrcTp5zjWr1wsJ8PIRZssZ8b/WMcMf71DJnit4EMU= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.28.0 h1:MirSo27VyNi7RJYP3078AA1+Cyzd2GB66qy3aUHvsWY= +github.com/rs/zerolog v1.28.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= 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/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= @@ -657,6 +665,7 @@ golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20210906170528-6f6e22806c34/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211025201205-69cdffdb9359/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211116061358-0a5406a5449c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211216021012-1d35b9e2eb4e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= @@ -844,6 +853,8 @@ gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI= gopkg.in/fsnotify.v1 v1.4.7/go.mod h1:Tz8NjZHkW78fSQdbUxIjBTcgA1z1m8ZHf0WmKUhAMys= gopkg.in/ini.v1 v1.67.0 h1:Dgnx+6+nfE+IfzjUEISNeydPJh9AXNNsWbGP9KzCsOA= gopkg.in/ini.v1 v1.67.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= +gopkg.in/natefinch/lumberjack.v2 v2.0.0 h1:1Lc07Kr7qY4U2YPouBjpCLxpiyxIVoxqXgkXLknAOE8= +gopkg.in/natefinch/lumberjack.v2 v2.0.0/go.mod h1:l0ndWWf7gzL7RNwBG7wST/UCcT4T24xpD6X8LsfU/+k= gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 h1:uRGJdciOHaEIrze2W8Q3AKkepLTh2hOroT7a+7czfdQ= gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7/go.mod h1:dt/ZhP58zS4L8KSrWDmTeBkI65Dw0HsyUHuEVlX15mw= gopkg.in/yaml.v2 v2.2.1/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= diff --git a/libs/cli/flags/log_level.go b/libs/log/log_level.go similarity index 70% rename from libs/cli/flags/log_level.go rename to libs/log/log_level.go index 6deb77fdf..5df30294e 100644 --- a/libs/cli/flags/log_level.go +++ b/libs/log/log_level.go @@ -1,11 +1,9 @@ -package flags +package log import ( "errors" "fmt" "strings" - - "github.com/line/ostracon/libs/log" ) const ( @@ -17,8 +15,9 @@ const ( // all other modules). // // Example: -// ParseLogLevel("consensus:debug,mempool:debug,*:error", log.NewOCLogger(os.Stdout), "info") -func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) (log.Logger, error) { +// +// ParseLogLevel("consensus:debug,mempool:debug,*:error", NewOCLogger(os.Stdout), "info") +func ParseLogLevel(lvl string, logger Logger, defaultLogLevelValue string) (Logger, error) { if lvl == "" { return nil, errors.New("empty log level") } @@ -30,10 +29,10 @@ func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) ( l = defaultLogLevelKey + ":" + l } - options := make([]log.Option, 0) + options := make([]Option, 0) isDefaultLogLevelSet := false - var option log.Option + var option Option var err error list := strings.Split(l, ",") @@ -48,7 +47,7 @@ func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) ( level := moduleAndLevel[1] if module == defaultLogLevelKey { - option, err = log.AllowLevel(level) + option, err = AllowLevel(level) if err != nil { return nil, fmt.Errorf("failed to parse default log level (pair %s, list %s): %w", item, l, err) } @@ -57,13 +56,13 @@ func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) ( } else { switch level { case "debug": - option = log.AllowDebugWith("module", module) + option = AllowDebugWith("module", module) case "info": - option = log.AllowInfoWith("module", module) + option = AllowInfoWith("module", module) case "error": - option = log.AllowErrorWith("module", module) + option = AllowErrorWith("module", module) case "none": - option = log.AllowNoneWith("module", module) + option = AllowNoneWith("module", module) default: return nil, fmt.Errorf("expected either \"info\", \"debug\", \"error\" or \"none\" log level, given %s (pair %s, list %s)", @@ -78,12 +77,12 @@ func ParseLogLevel(lvl string, logger log.Logger, defaultLogLevelValue string) ( // if "*" is not provided, set default global level if !isDefaultLogLevelSet { - option, err = log.AllowLevel(defaultLogLevelValue) + option, err = AllowLevel(defaultLogLevelValue) if err != nil { return nil, err } options = append(options, option) } - return log.NewFilter(logger, options...), nil + return NewFilter(logger, options...), nil } diff --git a/libs/cli/flags/log_level_test.go b/libs/log/log_level_test.go similarity index 91% rename from libs/cli/flags/log_level_test.go rename to libs/log/log_level_test.go index 25a34d3b1..0e63f0c04 100644 --- a/libs/cli/flags/log_level_test.go +++ b/libs/log/log_level_test.go @@ -1,11 +1,10 @@ -package flags_test +package log_test import ( "bytes" "strings" "testing" - tmflags "github.com/line/ostracon/libs/cli/flags" "github.com/line/ostracon/libs/log" ) @@ -44,7 +43,7 @@ func TestParseLogLevel(t *testing.T) { } for _, c := range correctLogLevels { - logger, err := tmflags.ParseLogLevel(c.lvl, jsonLogger, defaultLogLevelValue) + logger, err := log.ParseLogLevel(c.lvl, jsonLogger, defaultLogLevelValue) if err != nil { t.Fatal(err) } @@ -87,7 +86,7 @@ func TestParseLogLevel(t *testing.T) { incorrectLogLevel := []string{"some", "mempool:some", "*:some,mempool:error"} for _, lvl := range incorrectLogLevel { - if _, err := tmflags.ParseLogLevel(lvl, jsonLogger, defaultLogLevelValue); err == nil { + if _, err := log.ParseLogLevel(lvl, jsonLogger, defaultLogLevelValue); err == nil { t.Fatalf("Expected %s to produce error", lvl) } } diff --git a/libs/log/zerolog_logger.go b/libs/log/zerolog_logger.go new file mode 100644 index 000000000..f42e1e6b6 --- /dev/null +++ b/libs/log/zerolog_logger.go @@ -0,0 +1,129 @@ +package log + +import ( + "fmt" + "io" + + "github.com/rs/zerolog" + "gopkg.in/natefinch/lumberjack.v2" +) + +var _ Logger = (*ZeroLogWrapper)(nil) + +// ZeroLogWrapper provides a wrapper around a zerolog.Logger instance. It implements +// Tendermint's Logger interface. +type ZeroLogWrapper struct { + zerolog.Logger +} + +type ZeroLogConfig struct { + IsLogPlain bool + LogLevel string + + LogPath string + LogMaxAge int + LogMaxSize int + LogMaxBackups int +} + +func NewZeroLogConfig(isLogPlain bool, logLevel string, logPath string, logMaxAge int, logMaxSize int, logMaxBackups int) ZeroLogConfig { + return ZeroLogConfig{ + IsLogPlain: isLogPlain, + LogLevel: logLevel, + LogPath: logPath, + LogMaxAge: logMaxAge, + LogMaxSize: logMaxSize, + LogMaxBackups: logMaxBackups, + } +} + +func NewZeroLogLogger(cfg ZeroLogConfig, consoleWriter io.Writer) (Logger, error) { + var logWriter io.Writer + if cfg.IsLogPlain { + logWriter = zerolog.ConsoleWriter{ + Out: consoleWriter, + TimeFormat: "2006/01/02-15:04:05.999", + } + } else { + logWriter = consoleWriter + } + + var zeroLogLogger zerolog.Logger + if cfg.LogPath != "" { + // initialize the rotator + rotator := &lumberjack.Logger{ + Filename: cfg.LogPath, + MaxAge: cfg.LogMaxAge, + MaxSize: cfg.LogMaxSize, + MaxBackups: cfg.LogMaxBackups, + } + + // set log format + var fileLogWriter io.Writer + if cfg.IsLogPlain { + fileLogWriter = zerolog.ConsoleWriter{ + Out: rotator, + NoColor: true, + TimeFormat: "2006/01/02-15:04:05.999", + } + } else { + fileLogWriter = rotator + } + + zeroLogLogger = zerolog.New(zerolog.MultiLevelWriter(logWriter, fileLogWriter)).With().Timestamp().Logger() + } else { + zeroLogLogger = zerolog.New(logWriter).With().Timestamp().Logger() + } + + leveledZeroLogLogger, err := ParseLogLevel(cfg.LogLevel, ZeroLogWrapper{zeroLogLogger}, "info") + if err != nil { + return nil, fmt.Errorf("failed to parse log level (%s): %w", cfg.LogLevel, err) + } + + return leveledZeroLogLogger, nil +} + +func init() { + zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs +} + +// Info implements Tendermint's Logger interface and logs with level INFO. A set +// of key/value tuples may be provided to add context to the log. The number of +// tuples must be even and the key of the tuple must be a string. +func (z ZeroLogWrapper) Info(msg string, keyVals ...interface{}) { + z.Logger.Info().Fields(getLogFields(keyVals...)).Msg(msg) +} + +// Error implements Tendermint's Logger interface and logs with level ERR. A set +// of key/value tuples may be provided to add context to the log. The number of +// tuples must be even and the key of the tuple must be a string. +func (z ZeroLogWrapper) Error(msg string, keyVals ...interface{}) { + z.Logger.Error().Fields(getLogFields(keyVals...)).Msg(msg) +} + +// Debug implements Tendermint's Logger interface and logs with level DEBUG. A set +// of key/value tuples may be provided to add context to the log. The number of +// tuples must be even and the key of the tuple must be a string. +func (z ZeroLogWrapper) Debug(msg string, keyVals ...interface{}) { + z.Logger.Debug().Fields(getLogFields(keyVals...)).Msg(msg) +} + +// With returns a new wrapped logger with additional context provided by a set +// of key/value tuples. The number of tuples must be even and the key of the +// tuple must be a string. +func (z ZeroLogWrapper) With(keyVals ...interface{}) Logger { + return ZeroLogWrapper{z.Logger.With().Fields(getLogFields(keyVals...)).Logger()} +} + +func getLogFields(keyVals ...interface{}) map[string]interface{} { + if len(keyVals)%2 != 0 { + return nil + } + + fields := make(map[string]interface{}) + for i := 0; i < len(keyVals); i += 2 { + fields[keyVals[i].(string)] = keyVals[i+1] + } + + return fields +} diff --git a/libs/log/zerolog_logger_test.go b/libs/log/zerolog_logger_test.go new file mode 100644 index 000000000..b126ed7d2 --- /dev/null +++ b/libs/log/zerolog_logger_test.go @@ -0,0 +1,434 @@ +package log_test + +import ( + "bytes" + "fmt" + "io/ioutil" + "os" + "regexp" + "strings" + "testing" + "time" + + "github.com/line/ostracon/libs/log" +) + +func TestZeroLogLoggerLogsItsErrors(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:info", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + 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) + } + + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + if !strings.Contains(string(str), "foo") { + t.Errorf("expected file logger msg to contain ErrInvalidKey, got %s", msg) + } +} + +func TestZeroLogInfo(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:info", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + logger.Info("Client initialized with old header (trusted is more recent)", + "old", 42, + "trustedHeight", "forty two", + "trustedHash", fmt.Sprintf("%x", []byte("test me"))) + + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + const expectedMsg = `Client initialized with old header (trusted is more recent) old=42 trustedHash=74657374206d65 trustedHeight="forty two"` + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } +} + +func TestZeroLogDebug(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:debug", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + logger.Debug("Client initialized with old header (trusted is more recent)", + "old", 42, + "trustedHeight", "forty two", + "trustedHash", fmt.Sprintf("%x", []byte("test me"))) + + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + const expectedMsg = `Client initialized with old header (trusted is more recent) old=42 trustedHash=74657374206d65 trustedHeight="forty two"` + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } +} + +func TestZeroLogError(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:error", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + logger.Error("Client initialized with old header (trusted is more recent)", + "old", 42, + "trustedHeight", "forty two", + "trustedHash", fmt.Sprintf("%x", []byte("test me"))) + + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + const expectedMsg = `Client initialized with old header (trusted is more recent) old=42 trustedHash=74657374206d65 trustedHeight="forty two"` + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } +} + +func TestZeroLogLevelForModules(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "module1:debug,module2:info,*:error", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + + // logger level = debug + // debug O, info O, error O + { + loggerForModule1 := logger.With("module", "module1") + + // debug O + loggerForModule1.Debug("a1", "b1", "c1") + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg := "a1 b1=c1" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // info O + loggerForModule1.Info("a2", "b2", "c2") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a2 b2=c2" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // error O + loggerForModule1.Error("a3", "b3", "c3") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a3 b3=c3" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + } + + // logger level = info + // debug X, info O, error O + { + loggerForModule2 := logger.With("module", "module2") + + // debug X + loggerForModule2.Debug("a4", "b4", "c4") + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg := "a4 b4=c4" + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // info O + loggerForModule2.Info("a5", "b5", "c5") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a5 b5=c5" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // error O + loggerForModule2.Error("a6", "b6", "c6") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a6 b6=c6" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + } + + // logger level = error + // debug X, info X, error O + { + loggerForModule3 := logger.With("module", "module3") + + // debug X + loggerForModule3.Debug("a7", "b7", "c7") + msg := strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg := "a7 b7=c7" + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err := ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // info X + loggerForModule3.Info("a8", "b8", "c8") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a8 b8=c8" + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + + // error O + loggerForModule3.Error("a9", "b9", "c9") + msg = strings.TrimSpace(buf.String()) + msg = regexp.MustCompile(`\x1b\[[0-9;]*[a-zA-Z]`).ReplaceAllString(msg, "") + expectedMsg = "a9 b9=c9" + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + str, err = ioutil.ReadFile(filepath) + if err != nil { + t.Fatal(err) + } + msg = strings.TrimSpace(string(str)) + if !strings.Contains(msg, expectedMsg) { + t.Fatalf("received %s, expected %s", msg, expectedMsg) + } + } +} + +func TestZeroLogRotateFiles(t *testing.T) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + t.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:info", filepath, 1, 1, 2) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + t.Fatal(err) + } + + // it writes more than 1M logs so that two log files are created + msg := "0123456789abcdefghijklmnopqrstuvwxyz0123456789abcdefghijklmnopqrstuvwxyz0123456789abcdefghijklmnopqrstuvwxyz0123456789abcdefghijklmnopqrstuvwxyz0123456789abcdefghijklmnopqrstuvwxyz" + for i := 0; i < 6000; i++ { + logger.Info(msg) + } + + // check if only two log files is created + // ex) app.log, app-2022-12-16T10-21-41.295.log + files, err := ioutil.ReadDir(dir) + if err != nil { + t.Fatal(err) + } + if len(files) != 2 { + t.Fatalf("file count created %d, expected %d", len(files), 2) + } + + // change the filename of the backed up log file to one created 2 days ago + // ex) app-2022-12-16T10-21-41.295.log -> app-2022-12-14T10-21-41.295.log + now := time.Now().Add(-time.Hour * 48) + filename2 := fmt.Sprintf("app-%d-%02d-%02dT%02d-%02d-%02d.000.log", now.Year(), now.Month(), now.Day(), now.Hour(), now.Minute(), now.Second()) + for _, f := range files { + if f.Name() == "app.log" { + continue + } + + err = os.Rename(dir+"/"+f.Name(), dir+"/"+filename2) + if err != nil { + t.Fatalf("file rename failed old filename: %s, new filename: %s", dir+"/"+f.Name(), dir+"/"+filename2) + } + } + + // write new logs for rotating log file(remove old log file) + // ex) app.log, app-2022-12-16T10-21-43.374.log + for i := 0; i < 6000; i++ { + logger.Info(msg) + } + + // check if old log file is removed + files, err = ioutil.ReadDir(dir) + if err != nil { + t.Fatal(err) + } + if len(files) != 2 { + t.Fatalf("created %d, expected %d", len(files), 2) + } + for _, f := range files { + if f.Name() == filename2 { + t.Fatalf("The log file has not been removed yet") + } + } +} + +func BenchmarkZeroLogLoggerSimple(b *testing.B) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + b.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:info", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + b.Fatal(err) + } + + benchmarkRunner(b, logger, baseInfoMessage) +} + +func BenchmarkZeroLogLoggerContextual(b *testing.B) { + dir, err := ioutil.TempDir("/tmp", "zerolog-test") + if err != nil { + b.Fatal(err) + } + filepath := dir + "/app.log" + + var buf bytes.Buffer + config := log.NewZeroLogConfig(true, "*:info", filepath, 0, 100, 0) + logger, err := log.NewZeroLogLogger(config, &buf) + if err != nil { + b.Fatal(err) + } + + benchmarkRunner(b, logger, withInfoMessage) +} diff --git a/test/e2e/node/main.go b/test/e2e/node/main.go index d4595c388..1c5a398fa 100644 --- a/test/e2e/node/main.go +++ b/test/e2e/node/main.go @@ -16,7 +16,6 @@ import ( "github.com/line/ostracon/abci/server" "github.com/line/ostracon/config" "github.com/line/ostracon/crypto/ed25519" - tmflags "github.com/line/ostracon/libs/cli/flags" "github.com/line/ostracon/libs/log" tmnet "github.com/line/ostracon/libs/net" "github.com/line/ostracon/light" @@ -305,7 +304,7 @@ func setupNode() (*config.Config, log.Logger, *p2p.NodeKey, error) { logger = log.NewOCJSONLogger(log.NewSyncWriter(os.Stdout)) } - nodeLogger, err := tmflags.ParseLogLevel(tmcfg.LogLevel, logger, config.DefaultLogLevel) + nodeLogger, err := log.ParseLogLevel(tmcfg.LogLevel, logger, config.DefaultLogLevel) if err != nil { return nil, nil, nil, err } diff --git a/test/maverick/main.go b/test/maverick/main.go index a34da66ed..3b01275ea 100644 --- a/test/maverick/main.go +++ b/test/maverick/main.go @@ -12,7 +12,6 @@ import ( "github.com/line/ostracon/cmd/ostracon/commands/debug" cfg "github.com/line/ostracon/config" "github.com/line/ostracon/libs/cli" - tmflags "github.com/line/ostracon/libs/cli/flags" "github.com/line/ostracon/libs/log" tmos "github.com/line/ostracon/libs/os" tmrand "github.com/line/ostracon/libs/rand" @@ -70,7 +69,7 @@ var RootCmd = &cobra.Command{ logger = log.NewOCJSONLogger(log.NewSyncWriter(os.Stdout)) } - logger, err = tmflags.ParseLogLevel(config.LogLevel, logger, cfg.DefaultLogLevel) + logger, err = log.ParseLogLevel(config.LogLevel, logger, cfg.DefaultLogLevel) if err != nil { return err }