From e9390dfa4c2187ded61b490fd828fe7fc0283578 Mon Sep 17 00:00:00 2001 From: Spoorthi Satheesha <9302666+spoo-bar@users.noreply.github.com> Date: Tue, 28 Sep 2021 15:56:54 +0530 Subject: [PATCH] feat: adding zerolog logging to cosmovisor (#10217) * adding zerolog to cosmovisor * replacing println with logger * fixing tests * fixing err log format * addign changelog * fixing formatting * using fields in loggin * using fields in logging Co-authored-by: Jonathan Gimeno --- cosmovisor/CHANGELOG.md | 1 + cosmovisor/args.go | 2 +- cosmovisor/cmd/cosmovisor/main.go | 8 ++++---- cosmovisor/go.mod | 3 ++- cosmovisor/go.sum | 7 +++++++ cosmovisor/logger.go | 15 +++++++++++++++ cosmovisor/process.go | 18 +++++++----------- cosmovisor/scanner.go | 3 +-- cosmovisor/upgrade.go | 4 ++-- 9 files changed, 40 insertions(+), 21 deletions(-) create mode 100644 cosmovisor/logger.go diff --git a/cosmovisor/CHANGELOG.md b/cosmovisor/CHANGELOG.md index 6b5e609ea4a0..50b328fc6021 100644 --- a/cosmovisor/CHANGELOG.md +++ b/cosmovisor/CHANGELOG.md @@ -49,6 +49,7 @@ Ref: https://keepachangelog.com/en/1.0.0/ + [\#10018](https://github.com/cosmos/cosmos-sdk/pull/10018) Strict boolean argument parsing: cosmovisor will fail if user will not set correctly a boolean variable. Correct values are: "true", "false", "" (not setting) - all case not sensitive. + [\#10036](https://github.com/cosmos/cosmos-sdk/pull/10036) Improve logs when downloading the binary. ++ [\#10217](https://github.com/cosmos/cosmos-sdk/pull/10217) Replacing logging to use zerolog. ## v0.1 2021-08-06 diff --git a/cosmovisor/args.go b/cosmovisor/args.go index 6e96e5ab2387..20608332ecdb 100644 --- a/cosmovisor/args.go +++ b/cosmovisor/args.go @@ -247,7 +247,7 @@ func (cfg *Config) UpgradeInfo() UpgradeInfo { return cfg.currentUpgrade returnError: - fmt.Println("[cosmovisor], error reading", filename, err) + Logger.Error().Err(err).Str("filename", filename).Msg("failed to read") cfg.currentUpgrade.Name = "_" return cfg.currentUpgrade } diff --git a/cosmovisor/cmd/cosmovisor/main.go b/cosmovisor/cmd/cosmovisor/main.go index e4c9da8876ae..c0e9a97f414e 100644 --- a/cosmovisor/cmd/cosmovisor/main.go +++ b/cosmovisor/cmd/cosmovisor/main.go @@ -1,7 +1,6 @@ package main import ( - "fmt" "os" "github.com/cosmos/cosmos-sdk/cosmovisor" @@ -9,8 +8,9 @@ import ( ) func main() { + cosmovisor.SetupLogging() if err := Run(os.Args[1:]); err != nil { - fmt.Fprintf(os.Stderr, "[cosmovisor] %+v\n", err) + cosmovisor.Logger.Error().Err(err).Msg("") os.Exit(1) } } @@ -31,11 +31,11 @@ func Run(args []string) error { doUpgrade, err := launcher.Run(args, os.Stdout, os.Stderr) // if RestartAfterUpgrade, we launch after a successful upgrade (only condition LaunchProcess returns nil) for cfg.RestartAfterUpgrade && err == nil && doUpgrade { - fmt.Println("[cosmovisor] upgrade detected, relaunching the app ", cfg.Name) + cosmovisor.Logger.Info().Str("app", cfg.Name).Msg("upgrade detected, relaunching") doUpgrade, err = launcher.Run(args, os.Stdout, os.Stderr) } if doUpgrade && err == nil { - fmt.Println("[cosmovisor] upgrade detected, DAEMON_RESTART_AFTER_UPGRADE is off. Verify new upgrade and start cosmovisor again.") + cosmovisor.Logger.Info().Msg("upgrade detected, DAEMON_RESTART_AFTER_UPGRADE is off. Verify new upgrade and start cosmovisor again.") } return err diff --git a/cosmovisor/go.mod b/cosmovisor/go.mod index e297939c6e21..b117b9a58689 100644 --- a/cosmovisor/go.mod +++ b/cosmovisor/go.mod @@ -28,6 +28,7 @@ require ( github.com/mitchellh/go-homedir v1.0.0 // indirect github.com/mitchellh/go-testing-interface v1.0.0 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/rs/zerolog v1.25.0 // indirect github.com/ulikunitz/xz v0.5.5 // indirect go.opencensus.io v0.23.0 // indirect golang.org/x/lint v0.0.0-20210508222113-6edffad5e616 // indirect @@ -36,7 +37,7 @@ require ( golang.org/x/oauth2 v0.0.0-20210402161424-2e8d93401602 // indirect golang.org/x/sys v0.0.0-20210510120138-977fb7262007 // indirect golang.org/x/text v0.3.5 // indirect - golang.org/x/tools v0.1.2 // indirect + golang.org/x/tools v0.1.5 // indirect golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect google.golang.org/appengine v1.6.7 // indirect google.golang.org/grpc v1.38.0 // indirect diff --git a/cosmovisor/go.sum b/cosmovisor/go.sum index 7c56d718641b..60188ba715d7 100644 --- a/cosmovisor/go.sum +++ b/cosmovisor/go.sum @@ -53,6 +53,7 @@ github.com/client9/misspell v0.3.4/go.mod h1:qj6jICC3Q7zFZvVWo7KLAzC3yx5G7kyvSDk github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= github.com/cncf/udpa/go v0.0.0-20200629203442-efcf912fb354/go.mod h1:WmhPx2Nbnhtbo57+VJT5O0JRkEi1Wbu0z5j0R8u5Hbk= github.com/cncf/udpa/go v0.0.0-20201120205902-5459f2c99403/go.mod h1:WmhPx2Nbnhtbo57+VJT5O0JRkEi1Wbu0z5j0R8u5Hbk= +github.com/coreos/go-systemd/v22 v22.3.2/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= @@ -67,6 +68,7 @@ github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5Kwzbycv github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9AVAgeJqvqgH9Q5CA+iKCZ2gyEVpxRU= github.com/go-gl/glfw/v3.3/glfw v0.0.0-20191125211704-12ad95a8df72/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8= github.com/go-gl/glfw/v3.3/glfw v0.0.0-20200222043503-6f7a984d4dc4/go.mod h1:tQ2UAYgL5IevRw8kRxooKSPJfGvJ9fJQFa0TUsXzTg8= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q= github.com/golang/groupcache v0.0.0-20190702054246-869f871628b6/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= github.com/golang/groupcache v0.0.0-20191227052852-215e87163ea7/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc= @@ -171,10 +173,14 @@ github.com/otiai10/curr v1.0.0/go.mod h1:LskTG5wDwr8Rs+nNQ+1LlxRjAtTZZjtJW4rMXl6 github.com/otiai10/mint v1.3.0/go.mod h1:F5AjcsTsWUqX+Na9fpHb52P8pcRX2CI6A3ctIT91xUo= github.com/otiai10/mint v1.3.2 h1:VYWnrP5fXmz1MXvjuUvcBrXSjGE6xjON+axB/UrpO3E= github.com/otiai10/mint v1.3.2/go.mod h1:/yxELlJQ0ufhjUwhshSj+wFjZ78CnZ48/1wtmBH1OTc= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4= +github.com/rs/xid v1.3.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.25.0 h1:Rj7XygbUHKUlDPcVdoLyR91fJBsduXj5fRxyqIQj/II= +github.com/rs/zerolog v1.25.0/go.mod h1:7KHcEGe0QZPOm2IE4Kpb5rTh6n1h2hIgS5OOnu1rUaI= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs= github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4= @@ -397,6 +403,7 @@ golang.org/x/tools v0.0.0-20210105154028-b0ab187a4818/go.mod h1:emZCQorbCU4vsT4f golang.org/x/tools v0.1.0/go.mod h1:xkSsbof2nBLbhDlRMhhhyNLN/zl3eTqcnHD5viDpcZ0= golang.org/x/tools v0.1.2 h1:kRBLX7v7Af8W7Gdbbc908OJcdgtK8bOz9Uaj8/F1ACA= golang.org/x/tools v0.1.2/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk= +golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk= 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/cosmovisor/logger.go b/cosmovisor/logger.go new file mode 100644 index 000000000000..cc7b58720de6 --- /dev/null +++ b/cosmovisor/logger.go @@ -0,0 +1,15 @@ +package cosmovisor + +import ( + "os" + "time" + + "github.com/rs/zerolog" +) + +var Logger zerolog.Logger + +func SetupLogging() { + output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.Kitchen} + Logger = zerolog.New(output).With().Str("module", "cosmovisor").Timestamp().Logger() +} diff --git a/cosmovisor/process.go b/cosmovisor/process.go index e68255c038a3..4b740f0956fd 100644 --- a/cosmovisor/process.go +++ b/cosmovisor/process.go @@ -5,7 +5,6 @@ import ( "fmt" "io" "io/ioutil" - "log" "os" "os/exec" "os/signal" @@ -40,7 +39,7 @@ func (l Launcher) Run(args []string, stdout, stderr io.Writer) (bool, error) { if err := EnsureBinary(bin); err != nil { return false, fmt.Errorf("current binary is invalid: %w", err) } - fmt.Println("[cosmovisor] running ", bin, args) + Logger.Info().Str("path", bin).Strs("args", args).Msg("running app") cmd := exec.Command(bin, args...) cmd.Stdout = stdout cmd.Stderr = stderr @@ -53,7 +52,7 @@ func (l Launcher) Run(args []string, stdout, stderr io.Writer) (bool, error) { go func() { sig := <-sigs if err := cmd.Process.Signal(sig); err != nil { - log.Fatal(bin, "terminated. Error:", err) + Logger.Fatal().Err(err).Str("bin", bin).Msg("terminated") } }() @@ -92,7 +91,7 @@ func (l Launcher) WaitForUpgradeOrExit(cmd *exec.Cmd) (bool, error) { select { case <-l.fw.MonitorUpdate(currentUpgrade): // upgrade - kill the process and restart - fmt.Println("[cosmovisor] Daemon shutting down in an attempt to restart") + Logger.Info().Msg("Daemon shutting down in an attempt to restart") _ = cmd.Process.Kill() case err := <-cmdDone: l.fw.Stop() @@ -133,7 +132,7 @@ func doBackup(cfg *Config) error { stStr := fmt.Sprintf("%d-%d-%d", st.Year(), st.Month(), st.Day()) dst := filepath.Join(cfg.Home, fmt.Sprintf("data"+"-backup-%s", stStr)) - fmt.Printf("starting to take backup of data directory at time %s", st) + Logger.Info().Time("backup start time", st).Msg("starting to take backup of data directory") // copy the $DAEMON_HOME/data to a backup dir err = copy.Copy(filepath.Join(cfg.Home, "data"), dst) @@ -144,9 +143,7 @@ func doBackup(cfg *Config) error { // backup is done, lets check endtime to calculate total time taken for backup process et := time.Now() - timeTaken := et.Sub(st) - fmt.Printf("backup saved at location: %s, completed at time: %s\n"+ - "time taken to complete the backup: %s", dst, et, timeTaken) + Logger.Info().Str("backup saved at", dst).Time("backup completion time", et).TimeDiff("time taken to complete backup", et, st).Msg("backup completed") } return nil @@ -166,15 +163,14 @@ func doPreUpgrade(cfg *Config) error { if err != nil { if err.(*exec.ExitError).ProcessState.ExitCode() == 1 { - fmt.Println("pre-upgrade command does not exist. continuing the upgrade.") + Logger.Info().Msg("pre-upgrade command does not exist. continuing the upgrade.") return nil } if err.(*exec.ExitError).ProcessState.ExitCode() == 30 { return fmt.Errorf("pre-upgrade command failed : %w", err) } if err.(*exec.ExitError).ProcessState.ExitCode() == 31 { - fmt.Println("pre-upgrade command failed. retrying. attempt:", counter) - fmt.Println(err) + Logger.Error().Err(err).Int("attempt", counter).Msg("pre-upgrade command failed. retrying") continue } } diff --git a/cosmovisor/scanner.go b/cosmovisor/scanner.go index 7292c8ddffaf..d71cd3b1263b 100644 --- a/cosmovisor/scanner.go +++ b/cosmovisor/scanner.go @@ -4,7 +4,6 @@ import ( "encoding/json" "errors" "fmt" - "log" "os" "path/filepath" "time" @@ -94,7 +93,7 @@ func (fw *fileWatcher) CheckUpdate(currentUpgrade UpgradeInfo) bool { } info, err := parseUpgradeInfoFile(fw.filename) if err != nil { - log.Fatal("Can't parse upgrade info file. Err: ", err) + Logger.Fatal().Err(err).Msg("Can't parse upgrade info file") return false } if !fw.initialized { // daemon has restarted diff --git a/cosmovisor/upgrade.go b/cosmovisor/upgrade.go index 8ea5e91c6bb6..6b683fd92cea 100644 --- a/cosmovisor/upgrade.go +++ b/cosmovisor/upgrade.go @@ -36,11 +36,11 @@ func DoUpgrade(cfg *Config, info UpgradeInfo) error { } // If not there, then we try to download it... maybe - fmt.Println("[cosmovisor] No upgrade binary found, beginning to download it") + Logger.Info().Msg("No upgrade binary found, beginning to download it") if err := DownloadBinary(cfg, info); err != nil { return fmt.Errorf("cannot download binary. %w", err) } - fmt.Println("[cosmovisor] Downloading binary complete") + Logger.Info().Msg("Downloading binary complete") // and then set the binary again if err := EnsureBinary(cfg.UpgradeBin(info.Name)); err != nil {