diff --git a/clientcontroller/babylon.go b/clientcontroller/babylon.go index bfddfed1de912..cb22b7bbb84c0 100644 --- a/clientcontroller/babylon.go +++ b/clientcontroller/babylon.go @@ -24,7 +24,7 @@ import ( sdkquery "github.com/cosmos/cosmos-sdk/types/query" sttypes "github.com/cosmos/cosmos-sdk/x/staking/types" "github.com/cosmos/relayer/v2/relayer/provider" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/config" "github.com/babylonchain/btc-validator/types" @@ -36,13 +36,13 @@ type BabylonController struct { bbnClient *bbnclient.Client cfg *config.BBNConfig btcParams *chaincfg.Params - logger *logrus.Logger + logger *zap.Logger } func NewBabylonController( cfg *config.BBNConfig, btcParams *chaincfg.Params, - logger *logrus.Logger, + logger *zap.Logger, ) (*BabylonController, error) { bbnConfig := config.BBNConfigToBabylonConfig(cfg) @@ -683,7 +683,6 @@ func (bc *BabylonController) CreateBTCDelegation( return nil, err } - bc.logger.Infof("successfully submitted a BTC delegation, code: %v, height: %v, tx hash: %s", res.Code, res.Height, res.TxHash) return &types.TxResponse{TxHash: res.TxHash}, nil } @@ -709,7 +708,6 @@ func (bc *BabylonController) CreateBTCUndelegation( return nil, err } - bc.logger.Infof("successfully submitted a BTC undelegation, code: %v, height: %v, tx hash: %s", res.Code, res.Height, res.TxHash) return res, nil } diff --git a/clientcontroller/interface.go b/clientcontroller/interface.go index d2dafb3ca7641..d0d6eddaaa127 100644 --- a/clientcontroller/interface.go +++ b/clientcontroller/interface.go @@ -2,12 +2,13 @@ package clientcontroller import ( "fmt" - "github.com/btcsuite/btcd/chaincfg" "math/big" + "github.com/btcsuite/btcd/chaincfg" + "go.uber.org/zap" + "github.com/btcsuite/btcd/btcec/v2" "github.com/btcsuite/btcd/btcec/v2/schnorr" - "github.com/sirupsen/logrus" "github.com/babylonchain/btc-validator/config" "github.com/babylonchain/btc-validator/types" @@ -97,7 +98,7 @@ type CovenantAPIs interface { QueryUnbondingDelegations(limit uint64) ([]*types.Delegation, error) } -func NewClientController(chainName string, bbnConfig *config.BBNConfig, netParams *chaincfg.Params, logger *logrus.Logger) (ClientController, error) { +func NewClientController(chainName string, bbnConfig *config.BBNConfig, netParams *chaincfg.Params, logger *zap.Logger) (ClientController, error) { var ( cc ClientController err error diff --git a/covenant/config/config.go b/covenant/config/config.go index 6a5a18ca1094e..89fdbad05238c 100644 --- a/covenant/config/config.go +++ b/covenant/config/config.go @@ -2,16 +2,19 @@ package config import ( "fmt" - "github.com/sirupsen/logrus" "io" "os" "path/filepath" "time" - "github.com/babylonchain/btc-validator/config" + "go.uber.org/zap" + "github.com/btcsuite/btcd/btcutil" "github.com/btcsuite/btcd/chaincfg" "github.com/jessevdk/go-flags" + + "github.com/babylonchain/btc-validator/config" + "github.com/babylonchain/btc-validator/log" ) const ( @@ -57,7 +60,7 @@ type Config struct { // 2. Pre-parse the command line to check for an alternative config file // 3. Load configuration file overwriting defaults with any specified options // 4. Parse CLI options and overwrite/add any specified options -func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { +func LoadConfig(filePath string) (*Config, *zap.Logger, error) { // Pre-parse the command line options to pick up an alternative config // file. preCfg := DefaultConfig() @@ -86,18 +89,11 @@ func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { configFileError = err } - cfgLogger := logrus.New() - cfgLogger.Out = os.Stdout // Make sure everything we just loaded makes sense. if err := cfg.Validate(); err != nil { return nil, nil, err } - logRuslLevel, err := logrus.ParseLevel(cfg.LogLevel) - if err != nil { - return nil, nil, err - } - // At this point we know config is valid, create logger which also log to file logFilePath := filepath.Join(cfg.CovenantDir, defaultLogFilename) f, err := os.OpenFile(logFilePath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) @@ -106,20 +102,21 @@ func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { } mw := io.MultiWriter(os.Stdout, f) - cfgLogger.SetOutput(mw) - cfgLogger.SetLevel(logRuslLevel) + cfgLogger, err := log.NewRootLogger("console", cfg.LogLevel, mw) + if err != nil { + return nil, nil, err + } // Warn about missing config file only after all other configuration is // done. This prevents the warning on help messages and invalid // options. Note this should go directly before the return. if configFileError != nil { - cfgLogger.Warnf("%v", configFileError) if cfg.DumpCfg { - cfgLogger.Infof("Writing configuration file to %s", filePath) + cfgLogger.Info("Writing configuration file", zap.String("path", filePath)) fileParser := flags.NewParser(&cfg, flags.Default) err := flags.NewIniParser(fileParser).WriteFile(filePath, flags.IniIncludeComments|flags.IniIncludeDefaults) if err != nil { - cfgLogger.Warnf("Error writing configuration file: %v", err) + cfgLogger.Error("Error writing configuration file", zap.Error(err)) return nil, nil, err } } @@ -161,11 +158,6 @@ func (cfg *Config) Validate() error { return fmt.Errorf("unsupported Bitcoin network: %s", cfg.BitcoinNetwork) } - _, err = logrus.ParseLevel(cfg.LogLevel) - if err != nil { - return err - } - return nil } diff --git a/covenant/covenant.go b/covenant/covenant.go index f350692eeeb2e..29335446cf412 100644 --- a/covenant/covenant.go +++ b/covenant/covenant.go @@ -2,11 +2,14 @@ package covenant import ( "fmt" - "github.com/babylonchain/btc-validator/keyring" "strings" "sync" "time" + "go.uber.org/zap" + + "github.com/babylonchain/btc-validator/keyring" + "github.com/avast/retry-go/v4" "github.com/babylonchain/babylon/btcstaking" asig "github.com/babylonchain/babylon/crypto/schnorr-adaptor-signature" @@ -14,7 +17,6 @@ import ( bstypes "github.com/babylonchain/babylon/x/btcstaking/types" "github.com/btcsuite/btcd/btcec/v2" "github.com/btcsuite/btcd/btcutil" - "github.com/sirupsen/logrus" "github.com/babylonchain/btc-validator/clientcontroller" covcfg "github.com/babylonchain/btc-validator/covenant/config" @@ -43,7 +45,7 @@ type CovenantEmulator struct { config *covcfg.Config params *types.StakingParams - logger *logrus.Logger + logger *zap.Logger // input is used to pass passphrase to the keyring input *strings.Reader @@ -54,7 +56,7 @@ func NewCovenantEmulator( config *covcfg.Config, cc clientcontroller.ClientController, passphrase string, - logger *logrus.Logger, + logger *zap.Logger, ) (*CovenantEmulator, error) { input := strings.NewReader("") kr, err := keyring.CreateKeyring( @@ -185,13 +187,7 @@ func (ce *CovenantEmulator) AddCovenantSignature(btcDel *types.Delegation) (*Add // 4. submit covenant sigs res, err := ce.cc.SubmitCovenantSigs(ce.pk, stakingMsgTx.TxHash().String(), covSigs) - delPkHex := bbntypes.NewBIP340PubKeyFromBTCPK(btcDel.BtcPk).MarshalHex() if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - "validator_pks": btcDel.ValBtcPks, - "delegator_pk": delPkHex, - }).Error("failed to submit Covenant signature") return nil, err } @@ -326,13 +322,7 @@ func (ce *CovenantEmulator) AddCovenantUnbondingSignatures(del *types.Delegation covSlashingSigs, ) - delPkHex := bbntypes.NewBIP340PubKeyFromBTCPK(del.BtcPk).MarshalHex() - if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - "delegator_pk": delPkHex, - }).Error("failed to submit covenant signatures") return nil, err } @@ -365,55 +355,52 @@ func (ce *CovenantEmulator) covenantSigSubmissionLoop() { case <-covenantSigTicker.C: // 0. Update slashing address in case it is changed upon governance proposal if err := ce.UpdateParams(); err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - }).Error("failed to get staking params") + ce.logger.Debug("failed to get staking params", zap.Error(err)) continue } // 1. Get all pending delegations first, these are more important than the unbonding ones dels, err := ce.cc.QueryPendingDelegations(limit) if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - }).Error("failed to get pending delegations") + ce.logger.Debug("failed to get pending delegations", zap.Error(err)) continue } if len(dels) == 0 { - ce.logger.WithFields(logrus.Fields{}).Debug("no pending delegations are found") + ce.logger.Debug("no pending delegations are found") } for _, d := range dels { _, err := ce.AddCovenantSignature(d) if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - "del_btc_pk": d.BtcPk, - }).Error("failed to submit Covenant sig to the Bitcoin delegation") + delPkHex := bbntypes.NewBIP340PubKeyFromBTCPK(d.BtcPk).MarshalHex() + ce.logger.Error( + "failed to submit covenant signatures to the BTC delegation", + zap.String("del_btc_pk", delPkHex), + zap.Error(err), + ) } } // 2. Get all unbonding delegations unbondingDels, err := ce.cc.QueryUnbondingDelegations(limit) - if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - }).Error("failed to get pending delegations") + ce.logger.Debug("failed to get unbonding delegations", zap.Error(err)) continue } if len(unbondingDels) == 0 { - ce.logger.WithFields(logrus.Fields{}).Debug("no unbonding delegations are found") + ce.logger.Debug("no unbonding delegations are found") } for _, d := range unbondingDels { _, err := ce.AddCovenantUnbondingSignatures(d) if err != nil { - ce.logger.WithFields(logrus.Fields{ - "err": err, - "del_btc_pk": d.BtcPk, - }).Error("failed to submit Covenant sig to the Bitcoin undelegation") + delPkHex := bbntypes.NewBIP340PubKeyFromBTCPK(d.BtcPk).MarshalHex() + ce.logger.Error( + "failed to submit covenant signatures to the BTC undelegation", + zap.String("del_btc_pk", delPkHex), + zap.Error(err), + ) } } @@ -458,11 +445,12 @@ func (ce *CovenantEmulator) getParamsWithRetry() (*types.StakingParams, error) { } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - ce.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the consumer chain for the staking params") + ce.logger.Debug( + "failed to query the consumer chain for the staking params", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return nil, err } @@ -473,7 +461,7 @@ func (ce *CovenantEmulator) getParamsWithRetry() (*types.StakingParams, error) { func (ce *CovenantEmulator) Start() error { var startErr error ce.startOnce.Do(func() { - ce.logger.Infof("Starting Covenant Emulator") + ce.logger.Info("Starting Covenant Emulator") ce.wg.Add(1) go ce.covenantSigSubmissionLoop() @@ -485,7 +473,7 @@ func (ce *CovenantEmulator) Start() error { func (ce *CovenantEmulator) Stop() error { var stopErr error ce.stopOnce.Do(func() { - ce.logger.Infof("Stopping Covenant Emulator") + ce.logger.Info("Stopping Covenant Emulator") // Always stop the submission loop first to not generate additional events and actions ce.logger.Debug("Stopping submission loop") diff --git a/covenant/covenant_test.go b/covenant/covenant_test.go index f0b3f0f2639d6..2899c87aed052 100644 --- a/covenant/covenant_test.go +++ b/covenant/covenant_test.go @@ -12,8 +12,8 @@ import ( "github.com/btcsuite/btcd/chaincfg" "github.com/btcsuite/btcd/wire" "github.com/golang/mock/gomock" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/covenant" covcfg "github.com/babylonchain/btc-validator/covenant/config" @@ -52,7 +52,7 @@ func FuzzAddCovenantSig(f *testing.F) { require.NoError(t, err) // create and start covenant emulator - ce, err := covenant.NewCovenantEmulator(&covenantConfig, mockClientController, passphrase, logrus.New()) + ce, err := covenant.NewCovenantEmulator(&covenantConfig, mockClientController, passphrase, zap.NewNop()) require.NoError(t, err) err = ce.UpdateParams() diff --git a/covenant/service/server.go b/covenant/service/server.go index b0ed3b4a1b5cd..36162a8bdd7c0 100644 --- a/covenant/service/server.go +++ b/covenant/service/server.go @@ -5,7 +5,7 @@ import ( "sync/atomic" "github.com/lightningnetwork/lnd/signal" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/covenant" ) @@ -16,7 +16,7 @@ type CovenantServer struct { ce *covenant.CovenantEmulator - logger *logrus.Logger + logger *zap.Logger interceptor signal.Interceptor @@ -24,7 +24,7 @@ type CovenantServer struct { } // NewCovenantServer creates a new server with the given config. -func NewCovenantServer(l *logrus.Logger, ce *covenant.CovenantEmulator, sig signal.Interceptor) *CovenantServer { +func NewCovenantServer(l *zap.Logger, ce *covenant.CovenantEmulator, sig signal.Interceptor) *CovenantServer { return &CovenantServer{ logger: l, ce: ce, @@ -49,7 +49,7 @@ func (s *CovenantServer) RunUntilShutdown() error { return fmt.Errorf("failed to start covenant emulator: %w", err) } - s.logger.Infof("Covenant Emulator Daemon is fully active!") + s.logger.Info("Covenant Emulator Daemon is fully active!") // Wait for shutdown signal from either a graceful server stop or from // the interrupt handler. diff --git a/eotsmanager/cmd/eotsd/main.go b/eotsmanager/cmd/eotsd/main.go index e5795b57f6538..2e4f91cf64723 100644 --- a/eotsmanager/cmd/eotsd/main.go +++ b/eotsmanager/cmd/eotsd/main.go @@ -6,6 +6,7 @@ import ( "github.com/jessevdk/go-flags" "github.com/lightningnetwork/lnd/signal" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/eotsmanager" "github.com/babylonchain/btc-validator/eotsmanager/config" @@ -35,8 +36,7 @@ func main() { eotsManager, err := eotsmanager.NewLocalEOTSManager(cfg, cfgLogger) if err != nil { - cfgLogger.Errorf("failed to create EOTS manager: %v", err) - os.Exit(1) + cfgLogger.Fatal("failed to create EOTS manager", zap.Error(err)) } eotsServer := eotsservice.NewEOTSManagerServer(cfg, cfgLogger, eotsManager, shutdownInterceptor) diff --git a/eotsmanager/config/config.go b/eotsmanager/config/config.go index 82846bd7f912a..927c2083c1516 100644 --- a/eotsmanager/config/config.go +++ b/eotsmanager/config/config.go @@ -13,7 +13,9 @@ import ( "github.com/btcsuite/btcd/btcutil" "github.com/cosmos/cosmos-sdk/crypto/keyring" "github.com/jessevdk/go-flags" - "github.com/sirupsen/logrus" + "go.uber.org/zap" + + "github.com/babylonchain/btc-validator/log" ) const ( @@ -62,7 +64,7 @@ type Config struct { // 2. Pre-parse the command line to check for an alternative config file // 3. Load configuration file overwriting defaults with any specified options // 4. Parse CLI options and overwrite/add any specified options -func LoadConfig() (*Config, *logrus.Logger, error) { +func LoadConfig() (*Config, *zap.Logger, error) { // Pre-parse the command line options to pick up an alternative config // file. preCfg := DefaultConfig() @@ -116,18 +118,11 @@ func LoadConfig() (*Config, *logrus.Logger, error) { return nil, nil, err } - cfgLogger := logrus.New() - cfgLogger.Out = os.Stdout // Make sure everything we just loaded makes sense. if err := cfg.Validate(); err != nil { return nil, nil, err } - logRuslLevel, err := logrus.ParseLevel(cfg.LogLevel) - if err != nil { - return nil, nil, err - } - // TODO: Add log rotation // At this point we know config is valid, create logger which also log to file logFilePath := filepath.Join(cfg.LogDir, defaultLogFilename) @@ -137,20 +132,21 @@ func LoadConfig() (*Config, *logrus.Logger, error) { } mw := io.MultiWriter(os.Stdout, f) - cfgLogger.SetOutput(mw) - cfgLogger.SetLevel(logRuslLevel) + cfgLogger, err := log.NewRootLogger("console", cfg.LogLevel, mw) + if err != nil { + return nil, nil, err + } // Warn about missing config file only after all other configuration is // done. This prevents the warning on help messages and invalid // options. Note this should go directly before the return. if configFileError != nil { - cfgLogger.Warnf("%v", configFileError) if cfg.DumpCfg { - cfgLogger.Infof("Writing configuration file to %s", configFilePath) + cfgLogger.Info("Writing configuration file", zap.String("path", configFilePath)) fileParser := flags.NewParser(&cfg, flags.Default) err := flags.NewIniParser(fileParser).WriteFile(configFilePath, flags.IniIncludeComments|flags.IniIncludeDefaults) if err != nil { - cfgLogger.Warnf("Error writing configuration file: %v", err) + cfgLogger.Error("Error writing configuration file", zap.Error(err)) return nil, nil, err } } @@ -209,13 +205,7 @@ func (cfg *Config) Validate() error { } } - _, err := logrus.ParseLevel(cfg.LogLevel) - - if err != nil { - return err - } - - _, err = net.ResolveTCPAddr("tcp", cfg.RpcListener) + _, err := net.ResolveTCPAddr("tcp", cfg.RpcListener) if err != nil { return fmt.Errorf("invalid RPC listener address %s, %w", cfg.RpcListener, err) } diff --git a/eotsmanager/localmanager.go b/eotsmanager/localmanager.go index be485a94c982c..7058c89a708b0 100644 --- a/eotsmanager/localmanager.go +++ b/eotsmanager/localmanager.go @@ -13,7 +13,7 @@ import ( "github.com/cosmos/cosmos-sdk/crypto/keyring" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" "github.com/cosmos/go-bip39" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/codec" "github.com/babylonchain/btc-validator/eotsmanager/config" @@ -31,12 +31,12 @@ var _ EOTSManager = &LocalEOTSManager{} type LocalEOTSManager struct { kr keyring.Keyring es *EOTSStore - logger *logrus.Logger + logger *zap.Logger // input is to send passphrase to kr input *strings.Reader } -func NewLocalEOTSManager(eotsCfg *config.Config, logger *logrus.Logger) (*LocalEOTSManager, error) { +func NewLocalEOTSManager(eotsCfg *config.Config, logger *zap.Logger) (*LocalEOTSManager, error) { keyringDir := eotsCfg.KeyDirectory if keyringDir == "" { homeDir, err := os.UserHomeDir() @@ -127,7 +127,11 @@ func (lm *LocalEOTSManager) CreateKey(name, passphrase, hdPath string) ([]byte, return nil, err } - lm.logger.Infof("successfully created an EOTS key %s: %s", name, eotsPk.MarshalHex()) + lm.logger.Info( + "successfully created an EOTS key", + zap.String("key name", name), + zap.String("pk", eotsPk.MarshalHex()), + ) return eotsPk.MustMarshal(), nil } diff --git a/eotsmanager/localmanager_test.go b/eotsmanager/localmanager_test.go index f944aeabae85a..68ba7a1ea0596 100644 --- a/eotsmanager/localmanager_test.go +++ b/eotsmanager/localmanager_test.go @@ -6,8 +6,8 @@ import ( "testing" "github.com/babylonchain/babylon/testutil/datagen" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/eotsmanager" "github.com/babylonchain/btc-validator/eotsmanager/types" @@ -34,7 +34,7 @@ func FuzzCreateKey(f *testing.F) { require.NoError(t, err) }() - lm, err := eotsmanager.NewLocalEOTSManager(eotsCfg, logrus.New()) + lm, err := eotsmanager.NewLocalEOTSManager(eotsCfg, zap.NewNop()) require.NoError(t, err) valPk, err := lm.CreateKey(valName, passphrase, hdPath) @@ -67,7 +67,7 @@ func FuzzCreateRandomnessPairList(f *testing.F) { require.NoError(t, err) }() - lm, err := eotsmanager.NewLocalEOTSManager(eotsCfg, logrus.New()) + lm, err := eotsmanager.NewLocalEOTSManager(eotsCfg, zap.NewNop()) require.NoError(t, err) valPk, err := lm.CreateKey(valName, passphrase, hdPath) diff --git a/eotsmanager/service/server.go b/eotsmanager/service/server.go index 1098e9de5904d..c475e2c8fbd93 100644 --- a/eotsmanager/service/server.go +++ b/eotsmanager/service/server.go @@ -7,7 +7,7 @@ import ( "sync/atomic" "github.com/lightningnetwork/lnd/signal" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "google.golang.org/grpc" "github.com/babylonchain/btc-validator/eotsmanager" @@ -21,7 +21,7 @@ type Server struct { started int32 cfg *config.Config - logger *logrus.Logger + logger *zap.Logger rpcServer *rpcServer interceptor signal.Interceptor @@ -30,7 +30,7 @@ type Server struct { } // NewEOTSManagerServer creates a new server with the given config. -func NewEOTSManagerServer(cfg *config.Config, l *logrus.Logger, em eotsmanager.EOTSManager, sig signal.Interceptor) *Server { +func NewEOTSManagerServer(cfg *config.Config, l *zap.Logger, em eotsmanager.EOTSManager, sig signal.Interceptor) *Server { return &Server{ cfg: cfg, logger: l, @@ -73,7 +73,7 @@ func (s *Server) RunUntilShutdown() error { return fmt.Errorf("failed to start gRPC listener: %v", err) } - s.logger.Infof("EOTS Manager Daemon is fully active!") + s.logger.Info("EOTS Manager Daemon is fully active!") // Wait for shutdown signal from either a graceful server stop or from // the interrupt handler. @@ -92,7 +92,7 @@ func (s *Server) startGrpcListen(grpcServer *grpc.Server, listeners []net.Listen for _, lis := range listeners { wg.Add(1) go func(lis net.Listener) { - s.logger.Infof("RPC server listening on %s", lis.Addr()) + s.logger.Info("RPC server listening", zap.String("address", lis.Addr().String())) // Close the ready chan to indicate we are listening. defer lis.Close() diff --git a/go.mod b/go.mod index 4903f7a0c1eeb..d22cdd7c5236e 100644 --- a/go.mod +++ b/go.mod @@ -22,12 +22,13 @@ require ( github.com/gogo/protobuf v1.3.3 github.com/golang/mock v1.6.0 github.com/jessevdk/go-flags v1.5.0 + github.com/jsternberg/zap-logfmt v1.3.0 github.com/lightningnetwork/lnd v0.16.4-beta.rc1 - github.com/sirupsen/logrus v1.9.3 github.com/stretchr/testify v1.8.4 github.com/urfave/cli v1.22.14 go.etcd.io/bbolt v1.3.7 go.uber.org/atomic v1.10.0 + go.uber.org/zap v1.26.0 google.golang.org/grpc v1.59.0 google.golang.org/protobuf v1.31.0 ) @@ -153,7 +154,6 @@ require ( github.com/jinzhu/copier v0.3.5 // indirect github.com/jmespath/go-jmespath v0.4.0 // indirect github.com/jmhodges/levigo v1.0.0 // indirect - github.com/jsternberg/zap-logfmt v1.3.0 // indirect github.com/juju/fslock v0.0.0-20160525022230-4d5c94c67b4b // indirect github.com/kkdai/bstream v1.0.0 // indirect github.com/klauspost/compress v1.17.2 // indirect @@ -211,7 +211,6 @@ require ( github.com/zondax/ledger-go v0.14.3 // indirect go.opencensus.io v0.24.0 // indirect go.uber.org/multierr v1.11.0 // indirect - go.uber.org/zap v1.26.0 // indirect golang.org/x/crypto v0.15.0 // indirect golang.org/x/exp v0.0.0-20231006140011-7918f672742d // indirect golang.org/x/mod v0.14.0 // indirect @@ -239,7 +238,7 @@ require ( replace ( github.com/babylonchain/babylon => github.com/babylonchain/babylon-private v0.0.0-20231129064956-8ad04811f959 - github.com/babylonchain/rpc-client => github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231124142452-c4ed1331b6af + github.com/babylonchain/rpc-client => github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231128092309-ad2ef0696dc1 github.com/gogo/protobuf => github.com/regen-network/protobuf v1.3.3-alpha.regen.1 github.com/syndtr/goleveldb => github.com/syndtr/goleveldb v1.0.1-0.20210819022825-2ae1ddf74ef7 ) diff --git a/go.sum b/go.sum index 911be3ba359ec..09710a9e8a546 100644 --- a/go.sum +++ b/go.sum @@ -281,8 +281,8 @@ github.com/aws/aws-sdk-go v1.44.312/go.mod h1:aVsgQcEevwlmQ7qHE9I3h+dtQgpqhFB+i8 github.com/aws/aws-sdk-go-v2 v0.18.0/go.mod h1:JWVYvqSMppoMJC0x5wdwiImzgXTI9FuZwxzkQq9wy+g= github.com/babylonchain/babylon-private v0.0.0-20231129064956-8ad04811f959 h1:DbDrHk6UXI9Og0tnQscfJriTSseyD81DYTALQ9bnO1M= github.com/babylonchain/babylon-private v0.0.0-20231129064956-8ad04811f959/go.mod h1:hUJ0eyIpD9p9S+weU48es4P0FYDgIo2Nfg39AFiKj8Q= -github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231124142452-c4ed1331b6af h1:qzjmuFWgiamSvTXUQT/uDJEn4PA2ndV2Srq0qZauL1c= -github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231124142452-c4ed1331b6af/go.mod h1:2Dwjgml0C7vO/JSFs2ZJtgGrnP1oa5G21+DDQ6IqQTk= +github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231128092309-ad2ef0696dc1 h1:Cf1aNeXcSfZczocNxZZ1mM+KU4NDopzaIyi1fSoezxo= +github.com/babylonchain/rpc-client-private v0.7.0-rc0.0.20231128092309-ad2ef0696dc1/go.mod h1:M/tRKH7cc0gpAqCEpHTiaYob/6xoTD4v3A4FZQ3Y3ks= github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8= @@ -1063,8 +1063,8 @@ github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPx github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE= github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88= github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0= -github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= -github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= +github.com/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0= +github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc= github.com/smartystreets/goconvey v1.6.4/go.mod h1:syvi0/a8iFYH4r/RixwvyeAJjdLS9QV7WQ/tjFTllLA= github.com/soheilhy/cmux v0.1.4/go.mod h1:IM3LyeVVIOuxMH7sFAkER9+bJ4dT7Ms6E4xg4kGIyLM= @@ -1451,7 +1451,6 @@ golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.0.0-20220610221304-9f5ed59c137d/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220615213510-4f61da869c0c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220624220833-87e55d714810/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220728004956-3c1f35247d10/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= diff --git a/itest/e2e_test.go b/itest/e2e_test.go index b0d5849d4fe41..ee0afd45d711e 100644 --- a/itest/e2e_test.go +++ b/itest/e2e_test.go @@ -187,6 +187,12 @@ func TestCovenantLifeCycle(t *testing.T) { return false } - return len(del.BtcUndelegation.CovenantSlashingSigs) != 0 && len(del.BtcUndelegation.CovenantUnbondingSigs) != 0 + if len(del.BtcUndelegation.CovenantSlashingSigs) != 0 && len(del.BtcUndelegation.CovenantUnbondingSigs) != 0 { + return true + } + + return false }, 1*time.Minute, eventuallyPollTime) + + t.Log("covenant signatures for undelegation are submitted") } diff --git a/itest/eotsmanager_handler.go b/itest/eotsmanager_handler.go index f6c9398b6b775..5479fb7bd79c8 100644 --- a/itest/eotsmanager_handler.go +++ b/itest/eotsmanager_handler.go @@ -5,8 +5,8 @@ import ( "testing" "github.com/lightningnetwork/lnd/signal" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/eotsmanager" "github.com/babylonchain/btc-validator/eotsmanager/config" @@ -24,7 +24,7 @@ func NewEOTSServerHandler(t *testing.T, cfg *config.Config) *EOTSServerHandler { shutdownInterceptor, err := signal.Intercept() require.NoError(t, err) - logger := logrus.New() + logger := zap.NewNop() eotsManager, err := eotsmanager.NewLocalEOTSManager(cfg, logger) require.NoError(t, err) diff --git a/itest/test_manager.go b/itest/test_manager.go index 6bd3342772f06..ea65feede563e 100644 --- a/itest/test_manager.go +++ b/itest/test_manager.go @@ -22,8 +22,8 @@ import ( "github.com/cosmos/cosmos-sdk/crypto/keyring" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" stakingtypes "github.com/cosmos/cosmos-sdk/x/staking/types" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/covenant" @@ -82,9 +82,7 @@ func StartManager(t *testing.T) *TestManager { testDir, err := tempDirWithName("vale2etest") require.NoError(t, err) - logger := logrus.New() - logger.SetLevel(logrus.DebugLevel) - logger.Out = os.Stdout + logger := zap.NewNop() // 1. prepare covenant key, which will be used as input of Babylon node covenantConfig := defaultCovenantConfig(testDir) @@ -274,27 +272,6 @@ func (tm *TestManager) WaitForValNActiveDels(t *testing.T, btcPk *bbntypes.BIP34 return dels } -func (tm *TestManager) WaitForValNUnbondingDels(t *testing.T, btcPk *bbntypes.BIP340PubKey, n int) []*types.Delegation { - var ( - dels []*types.Delegation - err error - ) - // wait for our validator to: - // - detect new unbonding - // - send signature - require.Eventually(t, func() bool { - dels, err = tm.BabylonClient.QueryBTCValidatorDelegations(btcPk, 1000) - if err != nil { - return false - } - - return len(dels) == 1 && dels[0].BtcUndelegation != nil - - }, 1*time.Minute, eventuallyPollTime) - - return dels -} - func CheckDelsStatus(dels []*types.Delegation, btcHeight uint64, w uint64, status bstypes.BTCDelegationStatus) bool { allChecked := true for _, d := range dels { @@ -388,13 +365,6 @@ func (tm *TestManager) WaitForNFinalizedBlocks(t *testing.T, n int) []*types.Blo return blocks } -func (tm *TestManager) WaitForValStopped(t *testing.T, valPk *bbntypes.BIP340PubKey) { - require.Eventually(t, func() bool { - _, err := tm.Va.GetValidatorInstance(valPk) - return err != nil - }, eventuallyWaitTimeOut, eventuallyPollTime) -} - func (tm *TestManager) StopAndRestartValidatorAfterNBlocks(t *testing.T, n int, valIns *service.ValidatorInstance) { blockBeforeStop, err := tm.BabylonClient.QueryBestBlock() require.NoError(t, err) @@ -506,6 +476,8 @@ func (tm *TestManager) InsertBTCDelegation(t *testing.T, validatorPks []*btcec.P delegatorSig) require.NoError(t, err) + t.Log("successfully submitted a BTC delegation") + return &TestDelegationData{ DelegatorPrivKey: delBtcPrivKey, DelegatorKey: delBtcPubKey, @@ -574,6 +546,8 @@ func (tm *TestManager) InsertBTCUnbonding( serializedUnbondingTx, uint32(unbondingTime), unbondingValue, testUnbondingInfo.SlashingTx, unbondingSig, ) require.NoError(t, err) + + t.Log("successfully submitted a BTC undelegation") } func (tm *TestManager) GetParams(t *testing.T) *types.StakingParams { diff --git a/keyring/keyringcontroller_test.go b/keyring/keyringcontroller_test.go index fa6704688ef93..900e5ce5f7272 100644 --- a/keyring/keyringcontroller_test.go +++ b/keyring/keyringcontroller_test.go @@ -1,19 +1,22 @@ package keyring_test import ( - valstore "github.com/babylonchain/btc-validator/validator/store" "math/rand" "os" "testing" + "go.uber.org/zap" + + valstore "github.com/babylonchain/btc-validator/validator/store" + "github.com/babylonchain/babylon/types" - valkr "github.com/babylonchain/btc-validator/keyring" "github.com/btcsuite/btcd/chaincfg" "github.com/cosmos/cosmos-sdk/crypto/keyring" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + valkr "github.com/babylonchain/btc-validator/keyring" + "github.com/babylonchain/btc-validator/eotsmanager" "github.com/babylonchain/btc-validator/testutil" ) @@ -37,7 +40,7 @@ func FuzzCreatePoP(f *testing.F) { require.NoError(t, err) cfg := testutil.GenEOTSConfig(r, t) - em, err := eotsmanager.NewLocalEOTSManager(cfg, logrus.New()) + em, err := eotsmanager.NewLocalEOTSManager(cfg, zap.NewNop()) defer func() { err := os.RemoveAll(sdkCtx.KeyringDir) require.NoError(t, err) diff --git a/log/log.go b/log/log.go new file mode 100644 index 0000000000000..736c8557734f4 --- /dev/null +++ b/log/log.go @@ -0,0 +1,56 @@ +package log + +import ( + "fmt" + "io" + "strings" + "time" + + zaplogfmt "github.com/jsternberg/zap-logfmt" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func NewRootLogger(format string, level string, w io.Writer) (*zap.Logger, error) { + cfg := zap.NewProductionEncoderConfig() + cfg.EncodeTime = func(ts time.Time, encoder zapcore.PrimitiveArrayEncoder) { + encoder.AppendString(ts.UTC().Format("2006-01-02T15:04:05.000000Z07:00")) + } + cfg.LevelKey = "lvl" + + var enc zapcore.Encoder + switch format { + case "json": + enc = zapcore.NewJSONEncoder(cfg) + case "auto", "console": + enc = zapcore.NewConsoleEncoder(cfg) + case "logfmt": + enc = zaplogfmt.NewEncoder(cfg) + default: + return nil, fmt.Errorf("unrecognized log format %q", format) + } + + var lvl zapcore.Level + switch strings.ToLower(level) { + case "panic": + lvl = zap.PanicLevel + case "fatal": + lvl = zap.FatalLevel + case "error": + lvl = zap.ErrorLevel + case "warn", "warning": + lvl = zap.WarnLevel + case "info": + lvl = zap.InfoLevel + case "debug": + lvl = zap.DebugLevel + default: + return nil, fmt.Errorf("unsupported log level: %s", level) + } + + return zap.New(zapcore.NewCore( + enc, + zapcore.AddSync(w), + lvl, + )), nil +} diff --git a/validator/config/config.go b/validator/config/config.go index ffad175ce7fbe..16af999e9540e 100644 --- a/validator/config/config.go +++ b/validator/config/config.go @@ -2,7 +2,6 @@ package valcfg import ( "fmt" - "github.com/babylonchain/btc-validator/config" "io" "net" "os" @@ -12,10 +11,14 @@ import ( "strings" "time" + "go.uber.org/zap" + + "github.com/babylonchain/btc-validator/config" + "github.com/babylonchain/btc-validator/log" + "github.com/btcsuite/btcd/btcutil" "github.com/btcsuite/btcd/chaincfg" "github.com/jessevdk/go-flags" - "github.com/sirupsen/logrus" eotscfg "github.com/babylonchain/btc-validator/eotsmanager/config" ) @@ -60,7 +63,7 @@ var ( // Config is the main config for the vald cli command type Config struct { - DebugLevel string `long:"debuglevel" description:"Logging level for all subsystems" choice:"trace" choice:"debug" choice:"info" choice:"warn" choice:"error" choice:"fatal"` + LogLevel string `long:"loglevel" description:"Logging level for all subsystems" choice:"trace" choice:"debug" choice:"info" choice:"warn" choice:"error" choice:"fatal"` // ChainName and ChainID (if any) of the chain config identify a consumer chain ChainName string `long:"chainname" description:"the name of the consumer chain" choice:"babylon"` ValdDir string `long:"validatorddir" description:"The base directory that contains validator's data, logs, configuration file, etc."` @@ -111,7 +114,7 @@ func DefaultConfig() Config { ChainName: defaultChainName, ConfigFile: DefaultConfigFile, DataDir: defaultDataDir, - DebugLevel: defaultLogLevel, + LogLevel: defaultLogLevel, LogDir: defaultLogDir, DatabaseConfig: &dbCfg, BabylonConfig: &bbnCfg, @@ -150,7 +153,7 @@ func NewEOTSManagerConfigFromAppConfig(appCfg *Config) (*eotscfg.Config, error) return nil, err } return &eotscfg.Config{ - LogLevel: appCfg.DebugLevel, + LogLevel: appCfg.LogLevel, EOTSDir: appCfg.ValdDir, ConfigFile: appCfg.ConfigFile, KeyDirectory: appCfg.BabylonConfig.KeyDirectory, @@ -167,7 +170,7 @@ func NewEOTSManagerConfigFromAppConfig(appCfg *Config) (*eotscfg.Config, error) // 2. Pre-parse the command line to check for an alternative config file // 3. Load configuration file overwriting defaults with any specified options // 4. Parse CLI options and overwrite/add any specified options -func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { +func LoadConfig(filePath string) (*Config, *zap.Logger, error) { // Pre-parse the command line options to pick up an alternative config // file. preCfg := DefaultConfig() @@ -196,16 +199,11 @@ func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { configFileError = err } - cfgLogger := logrus.New() - cfgLogger.Out = os.Stdout // Make sure everything we just loaded makes sense. if err := cfg.Validate(); err != nil { return nil, nil, err } - // ignore error here as we already validated the value - logRuslLevel, _ := logrus.ParseLevel(cfg.DebugLevel) - // At this point we know config is valid, create logger which also log to file logFilePath := filepath.Join(cfg.LogDir, defaultLogFilename) f, err := os.OpenFile(logFilePath, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) @@ -214,20 +212,21 @@ func LoadConfig(filePath string) (*Config, *logrus.Logger, error) { } mw := io.MultiWriter(os.Stdout, f) - cfgLogger.Out = mw - cfgLogger.Level = logRuslLevel + cfgLogger, err := log.NewRootLogger("console", cfg.LogLevel, mw) + if err != nil { + return nil, nil, err + } // Warn about missing config file only after all other configuration is // done. This prevents the warning on help messages and invalid // options. Note this should go directly before the return. if configFileError != nil { - cfgLogger.Warnf("%v", configFileError) if cfg.DumpCfg { - cfgLogger.Infof("Writing configuration file to %s", filePath) + cfgLogger.Info("Writing configuration file", zap.String("path", filePath)) fileParser := flags.NewParser(&cfg, flags.Default) err := flags.NewIniParser(fileParser).WriteFile(filePath, flags.IniIncludeComments|flags.IniIncludeDefaults) if err != nil { - cfgLogger.Warnf("Error writing configuration file: %v", err) + cfgLogger.Error("Error writing configuration file", zap.Error(err)) return nil, nil, err } } @@ -303,12 +302,7 @@ func (cfg *Config) Validate() error { } } - _, err := logrus.ParseLevel(cfg.DebugLevel) - if err != nil { - return err - } - - _, err = net.ResolveTCPAddr("tcp", cfg.RpcListener) + _, err := net.ResolveTCPAddr("tcp", cfg.RpcListener) if err != nil { return fmt.Errorf("invalid RPC listener address %s, %w", cfg.RpcListener, err) } diff --git a/validator/service/app.go b/validator/service/app.go index 9bc26117c65ea..44c9213c52933 100644 --- a/validator/service/app.go +++ b/validator/service/app.go @@ -1,6 +1,7 @@ package service import ( + "encoding/hex" "fmt" "strings" "sync" @@ -8,11 +9,12 @@ import ( sdkmath "cosmossdk.io/math" bbntypes "github.com/babylonchain/babylon/types" bstypes "github.com/babylonchain/babylon/x/btcstaking/types" - valkr "github.com/babylonchain/btc-validator/keyring" "github.com/btcsuite/btcd/btcec/v2" "github.com/cosmos/cosmos-sdk/crypto/keyring" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" - "github.com/sirupsen/logrus" + "go.uber.org/zap" + + valkr "github.com/babylonchain/btc-validator/keyring" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/eotsmanager" @@ -40,7 +42,7 @@ type ValidatorApp struct { kr keyring.Keyring vs *valstore.ValidatorStore config *valcfg.Config - logger *logrus.Logger + logger *zap.Logger input *strings.Reader validatorManager *ValidatorManager @@ -53,7 +55,7 @@ type ValidatorApp struct { func NewValidatorAppFromConfig( config *valcfg.Config, - logger *logrus.Logger, + logger *zap.Logger, ) (*ValidatorApp, error) { cc, err := clientcontroller.NewClientController(config.ChainName, config.BabylonConfig, &config.ActiveNetParams, logger) if err != nil { @@ -80,7 +82,7 @@ func NewValidatorAppFromConfig( return nil, fmt.Errorf("failed to create EOTS manager client: %w", err) } // TODO add retry mechanism and ping to ensure the EOTS manager daemon is healthy - logger.Infof("successfully connected to a remote EOTS manager at %s", config.EOTSManagerAddress) + logger.Info("successfully connected to a remote EOTS manager", zap.String("address", config.EOTSManagerAddress)) } return NewValidatorApp(config, cc, em, logger) @@ -90,7 +92,7 @@ func NewValidatorApp( config *valcfg.Config, cc clientcontroller.ClientController, em eotsmanager.EOTSManager, - logger *logrus.Logger, + logger *zap.Logger, ) (*ValidatorApp, error) { input := strings.NewReader("") kr, err := valkr.CreateKeyring( @@ -229,7 +231,7 @@ func (app *ValidatorApp) getValPrivKey(valPk []byte) (*btcec.PrivateKey, error) func (app *ValidatorApp) Start() error { var startErr error app.startOnce.Do(func() { - app.logger.Infof("Starting ValidatorApp") + app.logger.Info("Starting ValidatorApp") app.eventWg.Add(1) go app.eventLoop() @@ -244,7 +246,7 @@ func (app *ValidatorApp) Start() error { func (app *ValidatorApp) Stop() error { var stopErr error app.stopOnce.Do(func() { - app.logger.Infof("Stopping ValidatorApp") + app.logger.Info("Stopping ValidatorApp") // Always stop the submission loop first to not generate additional events and actions app.logger.Debug("Stopping submission loop") @@ -353,12 +355,115 @@ func (app *ValidatorApp) handleCreateValidatorRequest(req *createValidatorReques return nil, fmt.Errorf("failed to save validator: %w", err) } - app.logger.WithFields(logrus.Fields{ - "btc_pub_key": valPk.MarshalHex(), - "name": req.keyName, - }).Debug("successfully created a validator") + app.logger.Info("successfully created a validator", + zap.String("btc_pk", valPk.MarshalHex()), + zap.String("key_name", req.keyName), + ) return &createValidatorResponse{ ValPk: valPk, }, nil } + +// main event loop for the validator app +func (app *ValidatorApp) eventLoop() { + defer app.eventWg.Done() + + for { + select { + case req := <-app.createValidatorRequestChan: + res, err := app.handleCreateValidatorRequest(req) + if err != nil { + req.errResponse <- err + continue + } + + req.successResponse <- &createValidatorResponse{ValPk: res.ValPk} + + case ev := <-app.validatorRegisteredEventChan: + valStored, err := app.vs.GetStoreValidator(ev.btcPubKey.MustMarshal()) + if err != nil { + // we always check if the validator is in the DB before sending the registration request + app.logger.Fatal( + "registered validator not found in DB", + zap.String("pk", ev.btcPubKey.MarshalHex()), + zap.Error(err), + ) + } + + // change the status of the validator to registered + err = app.vs.SetValidatorStatus(valStored, proto.ValidatorStatus_REGISTERED) + if err != nil { + app.logger.Fatal("failed to set validator status to REGISTERED", + zap.String("pk", ev.btcPubKey.MarshalHex()), + zap.Error(err), + ) + } + + // return to the caller + ev.successResponse <- &RegisterValidatorResponse{ + bbnPubKey: valStored.GetBabylonPK(), + btcPubKey: valStored.MustGetBIP340BTCPK(), + TxHash: ev.txHash, + } + + case <-app.eventQuit: + app.logger.Debug("exiting main event loop") + return + } + } +} + +func (app *ValidatorApp) registrationLoop() { + defer app.sentWg.Done() + for { + select { + case req := <-app.registerValidatorRequestChan: + // we won't do any retries here to not block the loop for more important messages. + // Most probably it fails due so some user error so we just return the error to the user. + // TODO: need to start passing context here to be able to cancel the request in case of app quiting + popBytes, err := req.pop.Marshal() + if err != nil { + req.errResponse <- err + continue + } + + res, err := app.cc.RegisterValidator( + req.bbnPubKey.Key, + req.btcPubKey.MustToBTCPK(), + popBytes, + req.commission.BigInt(), + req.description, + ) + + if err != nil { + app.logger.Error( + "failed to register validator", + zap.String("pk", req.btcPubKey.MarshalHex()), + zap.Error(err), + ) + req.errResponse <- err + continue + } + + app.logger.Info( + "successfully registered validator on babylon", + zap.String("btc_pk", req.btcPubKey.MarshalHex()), + zap.String("babylon_pk", hex.EncodeToString(req.bbnPubKey.Key)), + zap.String("txHash", res.TxHash), + ) + + app.validatorRegisteredEventChan <- &validatorRegisteredEvent{ + btcPubKey: req.btcPubKey, + bbnPubKey: req.bbnPubKey, + txHash: res.TxHash, + // pass the channel to the event so that we can send the response to the user which requested + // the registration + successResponse: req.successResponse, + } + case <-app.sentQuit: + app.logger.Debug("exiting registration loop") + return + } + } +} diff --git a/validator/service/app_test.go b/validator/service/app_test.go index f65f839828801..2a967495ef36f 100644 --- a/validator/service/app_test.go +++ b/validator/service/app_test.go @@ -8,8 +8,8 @@ import ( bbntypes "github.com/babylonchain/babylon/types" bstypes "github.com/babylonchain/babylon/x/btcstaking/types" "github.com/golang/mock/gomock" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/eotsmanager" "github.com/babylonchain/btc-validator/testutil" @@ -48,7 +48,7 @@ func FuzzRegisterValidator(f *testing.F) { mockClientController.EXPECT().QueryLatestFinalizedBlocks(gomock.Any()).Return(nil, nil).AnyTimes() eotsCfg, err := valcfg.NewEOTSManagerConfigFromAppConfig(&cfg) require.NoError(t, err) - logger := logrus.New() + logger := zap.NewNop() em, err := eotsmanager.NewLocalEOTSManager(eotsCfg, logger) require.NoError(t, err) app, err := service.NewValidatorApp(&cfg, mockClientController, em, logger) diff --git a/validator/service/chain_poller.go b/validator/service/chain_poller.go index 0ddf8047d950a..51b3c137c182d 100644 --- a/validator/service/chain_poller.go +++ b/validator/service/chain_poller.go @@ -6,7 +6,7 @@ import ( "time" "github.com/avast/retry-go/v4" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/types" @@ -37,11 +37,11 @@ type ChainPoller struct { cfg *cfg.ChainPollerConfig blockInfoChan chan *types.BlockInfo nextHeight uint64 - logger *logrus.Logger + logger *zap.Logger } func NewChainPoller( - logger *logrus.Logger, + logger *zap.Logger, cfg *cfg.ChainPollerConfig, cc clientcontroller.ClientController, ) *ChainPoller { @@ -57,7 +57,7 @@ func NewChainPoller( func (cp *ChainPoller) Start(startHeight uint64) error { var startErr error cp.startOnce.Do(func() { - cp.logger.Infof("Starting the chain poller") + cp.logger.Info("Starting the chain poller") err := cp.validateStartHeight(startHeight) if err != nil { @@ -77,7 +77,7 @@ func (cp *ChainPoller) Start(startHeight uint64) error { func (cp *ChainPoller) Stop() error { var stopError error cp.stopOnce.Do(func() { - cp.logger.Infof("Stopping the chain poller") + cp.logger.Info("Stopping the chain poller") err := cp.cc.Close() if err != nil { stopError = err @@ -110,11 +110,12 @@ func (cp *ChainPoller) latestBlockWithRetry() (*types.BlockInfo, error) { } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - cp.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the consumer chain for the latest block") + cp.logger.Debug( + "failed to query the consumer chain for the latest block", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return nil, err } @@ -133,12 +134,13 @@ func (cp *ChainPoller) blockWithRetry(height uint64) (*types.BlockInfo, error) { } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - cp.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "height": height, - "error": err, - }).Debug("failed to query the consumer chain for the block") + cp.logger.Debug( + "failed to query the consumer chain for the latest block", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Uint64("height", height), + zap.Error(err), + ) })); err != nil { return nil, err } @@ -158,9 +160,7 @@ func (cp *ChainPoller) validateStartHeight(startHeight uint64) error { for { lastestBlock, err := cp.latestBlockWithRetry() if err != nil { - cp.logger.WithFields(logrus.Fields{ - "error": err, - }).Error("Failed to query babylon for the latest status") + cp.logger.Debug("failed to query babylon for the latest status", zap.Error(err)) continue } @@ -182,9 +182,7 @@ func (cp *ChainPoller) waitForActivation() { for { activatedHeight, err := cp.cc.QueryActivatedHeight() if err != nil { - cp.logger.WithFields(logrus.Fields{ - "error": err, - }).Debug("failed to query the consumer chain for the activated height") + cp.logger.Debug("failed to query the consumer chain for the activated height", zap.Error(err)) } else { if cp.GetNextHeight() < activatedHeight { cp.SetNextHeight(activatedHeight) @@ -207,7 +205,7 @@ func (cp *ChainPoller) pollChain() { cp.waitForActivation() - var failedCycles uint64 + var failedCycles uint32 for { // TODO: Handlig of request cancellation, as otherwise shutdown will be blocked @@ -216,24 +214,24 @@ func (cp *ChainPoller) pollChain() { block, err := cp.blockWithRetry(blockToRetrieve) if err != nil { failedCycles++ - cp.logger.WithFields(logrus.Fields{ - "error": err, - "currFailures": failedCycles, - "blockToGet": blockToRetrieve, - }).Error("failed to query the consumer chain for the block") + cp.logger.Debug( + "failed to query the consumer chain for the block", + zap.Uint32("current_failures", failedCycles), + zap.Uint64("block_to_retrieve", blockToRetrieve), + zap.Error(err), + ) } else { // no error and we got the header we wanted to get, bump the state and push // notification about data cp.SetNextHeight(blockToRetrieve + 1) failedCycles = 0 - cp.logger.WithFields(logrus.Fields{ - "height": block.Height, - }).Info("the poller retrieved the block from the consumer chain") + cp.logger.Info("the poller retrieved the block from the consumer chain", + zap.Uint64("height", block.Height)) - // Push the data to the channel. - // If the cosumers are to slow i.e the buffer is full, this will block and we will - // stop retrieving data from the node. + // push the data to the channel + // Note: if the consumer is too slow -- the buffer is full + // the channel will block, and we will stop retrieving data from the node cp.blockInfoChan <- block } diff --git a/validator/service/event_loop.go b/validator/service/event_loop.go deleted file mode 100644 index a4ea4bde8859a..0000000000000 --- a/validator/service/event_loop.go +++ /dev/null @@ -1,111 +0,0 @@ -package service - -import ( - "encoding/hex" - - "github.com/sirupsen/logrus" - - "github.com/babylonchain/btc-validator/validator/proto" -) - -// main event loop for the validator app -func (app *ValidatorApp) eventLoop() { - defer app.eventWg.Done() - - for { - select { - case req := <-app.createValidatorRequestChan: - res, err := app.handleCreateValidatorRequest(req) - if err != nil { - req.errResponse <- err - continue - } - - req.successResponse <- &createValidatorResponse{ValPk: res.ValPk} - - case ev := <-app.validatorRegisteredEventChan: - valStored, err := app.vs.GetStoreValidator(ev.btcPubKey.MustMarshal()) - - if err != nil { - // we always check if the validator is in the DB before sending the registration request - app.logger.WithFields(logrus.Fields{ - "btc_pk": ev.btcPubKey.MarshalHex(), - "babylon_pk": hex.EncodeToString(ev.bbnPubKey.Key), - }).Fatal("registered validator not found in DB") - } - - // change the status of the validator to registered - err = app.vs.SetValidatorStatus(valStored, proto.ValidatorStatus_REGISTERED) - - if err != nil { - app.logger.WithFields(logrus.Fields{ - "bbn_pk": ev.bbnPubKey, - }).Fatal("err while saving validator to DB") - } - - // return to the caller - ev.successResponse <- &RegisterValidatorResponse{ - bbnPubKey: valStored.GetBabylonPK(), - btcPubKey: valStored.MustGetBIP340BTCPK(), - TxHash: ev.txHash, - } - - case <-app.eventQuit: - app.logger.Debug("exiting main eventLoop") - return - } - } -} - -func (app *ValidatorApp) registrationLoop() { - defer app.sentWg.Done() - for { - select { - case req := <-app.registerValidatorRequestChan: - // we won't do any retries here to not block the loop for more important messages. - // Most probably it fails due so some user error so we just return the error to the user. - // TODO: need to start passing context here to be able to cancel the request in case of app quiting - popBytes, err := req.pop.Marshal() - if err != nil { - req.errResponse <- err - continue - } - - res, err := app.cc.RegisterValidator( - req.bbnPubKey.Key, - req.btcPubKey.MustToBTCPK(), - popBytes, - req.commission.BigInt(), - req.description, - ) - - if err != nil { - app.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk": req.btcPubKey.MarshalHex(), - "babylon_pk": hex.EncodeToString(req.bbnPubKey.Key), - }).Error("failed to register validator") - req.errResponse <- err - continue - } - - app.logger.WithFields(logrus.Fields{ - "btc_pk": req.btcPubKey.MarshalHex(), - "babylon_pk": hex.EncodeToString(req.bbnPubKey.Key), - "txHash": res.TxHash, - }).Info("successfully registered validator on babylon") - - app.validatorRegisteredEventChan <- &validatorRegisteredEvent{ - btcPubKey: req.btcPubKey, - bbnPubKey: req.bbnPubKey, - txHash: res.TxHash, - // pass the channel to the event so that we can send the response to the user which requested - // the registration - successResponse: req.successResponse, - } - case <-app.sentQuit: - app.logger.Debug("exiting sentToBabylonLoop") - return - } - } -} diff --git a/validator/service/fastsync.go b/validator/service/fastsync.go index bb6b679c7396b..0a7e7c8252024 100644 --- a/validator/service/fastsync.go +++ b/validator/service/fastsync.go @@ -3,7 +3,7 @@ package service import ( "fmt" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/types" ) @@ -78,11 +78,12 @@ func (v *ValidatorInstance) FastSync(startHeight, endHeight uint64) (*FastSyncRe responses = append(responses, res) - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "start_height": catchUpBlocks[0].Height, - "synced_height": syncedHeight, - }).Debug("the validator is catching up by sending finality signatures in a batch") + v.logger.Debug( + "the validator is catching up by sending finality signatures in a batch", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("start_height", catchUpBlocks[0].Height), + zap.Uint64("synced_height", syncedHeight), + ) } v.MustSetLastProcessedHeight(endHeight) diff --git a/validator/service/server.go b/validator/service/server.go index 59b9443bc8713..85ed5feed5a42 100644 --- a/validator/service/server.go +++ b/validator/service/server.go @@ -7,7 +7,7 @@ import ( "sync/atomic" "github.com/lightningnetwork/lnd/signal" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "google.golang.org/grpc" valcfg "github.com/babylonchain/btc-validator/validator/config" @@ -20,7 +20,7 @@ type Server struct { started int32 cfg *valcfg.Config - logger *logrus.Logger + logger *zap.Logger rpcServer *rpcServer interceptor signal.Interceptor @@ -29,7 +29,7 @@ type Server struct { } // NewValidatorServer creates a new server with the given config. -func NewValidatorServer(cfg *valcfg.Config, l *logrus.Logger, v *ValidatorApp, sig signal.Interceptor) *Server { +func NewValidatorServer(cfg *valcfg.Config, l *zap.Logger, v *ValidatorApp, sig signal.Interceptor) *Server { return &Server{ cfg: cfg, logger: l, @@ -72,7 +72,7 @@ func (s *Server) RunUntilShutdown() error { return fmt.Errorf("failed to start gRPC listener: %v", err) } - s.logger.Infof("BTC Validator Daemon is fully active!") + s.logger.Info("BTC Validator Daemon is fully active!") // Wait for shutdown signal from either a graceful server stop or from // the interrupt handler. @@ -91,7 +91,7 @@ func (s *Server) startGrpcListen(grpcServer *grpc.Server, listeners []net.Listen for _, lis := range listeners { wg.Add(1) go func(lis net.Listener) { - s.logger.Infof("RPC server listening on %s", lis.Addr()) + s.logger.Info("RPC server listening", zap.String("address", lis.Addr().String())) // Close the ready chan to indicate we are listening. defer lis.Close() diff --git a/validator/service/types.go b/validator/service/types.go index ecf5ace89f2bc..3eaff46795eca 100644 --- a/validator/service/types.go +++ b/validator/service/types.go @@ -8,7 +8,7 @@ import ( btcstakingtypes "github.com/babylonchain/babylon/x/btcstaking/types" "github.com/btcsuite/btcd/btcec/v2" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" - "github.com/sirupsen/logrus" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/validator/proto" valstore "github.com/babylonchain/btc-validator/validator/store" @@ -147,11 +147,8 @@ func (v *ValidatorInstance) SetStatus(s proto.ValidatorStatus) error { func (v *ValidatorInstance) MustSetStatus(s proto.ValidatorStatus) { if err := v.SetStatus(s); err != nil { - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - "status": s.String(), - }).Fatal("failed to set validator status") + v.logger.Fatal("failed to set validator status", + zap.String("pk", v.GetBtcPkHex()), zap.String("status", s.String())) } } @@ -161,11 +158,8 @@ func (v *ValidatorInstance) SetLastProcessedHeight(height uint64) error { func (v *ValidatorInstance) MustSetLastProcessedHeight(height uint64) { if err := v.SetLastProcessedHeight(height); err != nil { - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - "height": height, - }).Fatal("failed to set last processed height") + v.logger.Fatal("failed to set last processed height", + zap.String("pk", v.GetBtcPkHex()), zap.Uint64("last_processed_height", height)) } } @@ -175,11 +169,8 @@ func (v *ValidatorInstance) SetLastCommittedHeight(height uint64) error { func (v *ValidatorInstance) MustSetLastCommittedHeight(height uint64) { if err := v.SetLastCommittedHeight(height); err != nil { - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - "height": height, - }).Fatal("failed to set last committed height") + v.logger.Fatal("failed to set last committed height", + zap.String("pk", v.GetBtcPkHex()), zap.Uint64("last_committed_height", height)) } } @@ -189,11 +180,8 @@ func (v *ValidatorInstance) updateStateAfterFinalitySigSubmission(height uint64) func (v *ValidatorInstance) MustUpdateStateAfterFinalitySigSubmission(height uint64) { if err := v.updateStateAfterFinalitySigSubmission(height); err != nil { - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - "height": height, - }).Fatal("failed to update state after finality sig submission") + v.logger.Fatal("failed to update state after finality signature submitted", + zap.String("pk", v.GetBtcPkHex()), zap.Uint64("height", height)) } } diff --git a/validator/service/validator_instance.go b/validator/service/validator_instance.go index 40b401d6a29c3..80f8e48c4a3ac 100644 --- a/validator/service/validator_instance.go +++ b/validator/service/validator_instance.go @@ -14,14 +14,14 @@ import ( "github.com/btcsuite/btcd/btcec/v2" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" "github.com/gogo/protobuf/jsonpb" - "github.com/sirupsen/logrus" "go.uber.org/atomic" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/eotsmanager" - "github.com/babylonchain/btc-validator/validator/proto" "github.com/babylonchain/btc-validator/types" valcfg "github.com/babylonchain/btc-validator/validator/config" + "github.com/babylonchain/btc-validator/validator/proto" valstore "github.com/babylonchain/btc-validator/validator/store" ) @@ -32,7 +32,7 @@ type ValidatorInstance struct { state *valState cfg *valcfg.Config - logger *logrus.Logger + logger *zap.Logger em eotsmanager.EOTSManager cc clientcontroller.ClientController poller *ChainPoller @@ -61,7 +61,7 @@ func NewValidatorInstance( em eotsmanager.EOTSManager, passphrase string, errChan chan<- *CriticalError, - logger *logrus.Logger, + logger *zap.Logger, ) (*ValidatorInstance, error) { v, err := s.GetStoreValidator(valPk.MustMarshal()) if err != nil { @@ -97,14 +97,15 @@ func (v *ValidatorInstance) Start() error { return fmt.Errorf("the validator instance %s is already started", v.GetBtcPkHex()) } - v.logger.Infof("Starting thread handling validator %s", v.GetBtcPkHex()) + v.logger.Info("Starting validator instance", zap.String("pk", v.GetBtcPkHex())) startHeight, err := v.bootstrap() if err != nil { return fmt.Errorf("failed to bootstrap the validator %s: %w", v.GetBtcPkHex(), err) } - v.logger.Infof("the validator %s has been bootstrapped to %v", v.GetBtcPkHex(), startHeight) + v.logger.Info("the validator %s has been bootstrapped", + zap.String("pk", v.GetBtcPkHex()), zap.Uint64("height", startHeight)) poller := NewChainPoller(v.logger, v.cfg.PollerConfig, v.cc) @@ -158,12 +159,12 @@ func (v *ValidatorInstance) Stop() error { return fmt.Errorf("failed to stop the poller: %w", err) } - v.logger.Infof("stopping thread handling validator %s", v.GetBtcPkHex()) + v.logger.Info("stopping validator instance", zap.String("pk", v.GetBtcPkHex())) close(v.quit) v.wg.Wait() - v.logger.Debugf("the thread handling validator %s is successfully stopped", v.GetBtcPkHex()) + v.logger.Info("the validator instance %s is successfully stopped", zap.String("pk", v.GetBtcPkHex())) return nil } @@ -178,17 +179,18 @@ func (v *ValidatorInstance) finalitySigSubmissionLoop() { for { select { case b := <-v.poller.GetBlockInfoChan(): - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": b.Height, - }).Debug("the validator received a new block, start processing") + v.logger.Debug( + "the validator received a new block, start processing", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("height", b.Height), + ) if b.Height <= v.GetLastProcessedHeight() { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": b.Height, - "last_processed_height": v.GetLastProcessedHeight(), - "last_voted_height": v.GetLastVotedHeight(), - }).Debug("the block has been processed before, skip processing") + v.logger.Debug( + "the block has been processed before, skip processing", + zap.Uint64("height", b.Height), + zap.Uint64("last_processed_height", v.GetLastProcessedHeight()), + zap.Uint64("last_voted_height", v.GetLastVotedHeight()), + ) continue } // use the copy of the block to avoid the impact to other receivers @@ -210,13 +212,13 @@ func (v *ValidatorInstance) finalitySigSubmissionLoop() { v.reportCriticalErr(err) continue } - if res != nil { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": b.Height, - "tx_hash": res.TxHash, - }).Info("successfully submitted a finality signature to the consumer chain") - } + v.logger.Info( + "successfully submitted a finality signature to the consumer chain", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("height", b.Height), + zap.String("tx_hash", res.TxHash), + ) + case targetBlock := <-v.laggingTargetChan: res, err := v.tryFastSync(targetBlock) v.isLagging.Store(false) @@ -225,20 +227,21 @@ func (v *ValidatorInstance) finalitySigSubmissionLoop() { v.reportCriticalErr(err) continue } - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - }).Error("failed to sync up, will try again later") + v.logger.Debug( + "failed to sync up, will try again later", + zap.String("pk", v.GetBtcPkHex()), + zap.Error(err), + ) continue } // response might be nil if sync is not needed if res != nil { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "tx_hashes": res.Responses, - "synced_height": res.SyncedHeight, - "last_processed_height": res.LastProcessedHeight, - }).Info("successfully synced to the latest block") + v.logger.Info( + "fast sync is finished", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("synced_height", res.SyncedHeight), + zap.Uint64("last_processed_height", res.LastProcessedHeight), + ) // set the poller to fetch blocks that have not been processed v.poller.SetNextHeightAndClearBuffer(v.GetLastProcessedHeight() + 1) @@ -269,12 +272,14 @@ func (v *ValidatorInstance) randomnessCommitmentLoop() { v.reportCriticalErr(err) continue } + // txRes could be nil if no need to commit more randomness if txRes != nil { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "last_committed_height": v.GetLastCommittedHeight(), - "tx_hash": txRes.TxHash, - }).Info("successfully committed public randomness to the consumer chain") + v.logger.Info( + "successfully committed public randomness to the consumer chain", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("last_committed_height", v.GetLastCommittedHeight()), + zap.String("tx_hash", txRes.TxHash), + ) } case <-v.quit: @@ -305,10 +310,11 @@ func (v *ValidatorInstance) checkLaggingLoop() { latestBlock, err := v.getLatestBlockWithRetry() if err != nil { - v.logger.WithFields(logrus.Fields{ - "err": err, - "btc_pk_hex": v.GetBtcPkHex(), - }).Error("failed to get the latest block of the consumer chain") + v.logger.Debug( + "failed to get the latest block of the consumer chain", + zap.String("pk", v.GetBtcPkHex()), + zap.Error(err), + ) continue } @@ -332,10 +338,11 @@ func (v *ValidatorInstance) tryFastSync(targetBlock *types.BlockInfo) (*FastSync if err := v.SetLastProcessedHeight(targetBlock.Height); err != nil { return nil, err } - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": targetBlock.Height, - }).Debug("insufficient public randomness, jumping to the latest block") + v.logger.Debug( + "insufficient public randomness, jumping to the latest block", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("target_height", targetBlock.Height), + ) return nil, nil } @@ -345,10 +352,11 @@ func (v *ValidatorInstance) tryFastSync(targetBlock *types.BlockInfo) (*FastSync return nil, err } if lastFinalizedBlocks == nil { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": targetBlock.Height, - }).Debug("no finalized blocks yet, no need to catch up") + v.logger.Debug( + "no finalized blocks yet, no need to catch up", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("height", targetBlock.Height), + ) return nil, nil } @@ -382,21 +390,23 @@ func (v *ValidatorInstance) tryFastSync(targetBlock *types.BlockInfo) (*FastSync func (v *ValidatorInstance) shouldSubmitFinalitySignature(b *types.BlockInfo) (bool, error) { // check last voted height if v.GetLastVotedHeight() >= b.Height { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": b.Height, - "last_voted_height": v.GetLastVotedHeight(), - }).Debug("the block has been voted before, skip voting") + v.logger.Debug( + "the block has been voted before, skip voting", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("block_height", b.Height), + zap.Uint64("last_voted_height", v.GetLastVotedHeight()), + ) return false, nil } // check last committed height if v.GetLastCommittedHeight() < b.Height { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "last_committed_height": v.GetLastCommittedHeight(), - "block_height": b.Height, - }).Debug("public rand is not committed, skip voting") + v.logger.Debug( + "public rand is not committed, skip voting", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("block_height", b.Height), + zap.Uint64("last_committed_height", v.GetLastCommittedHeight()), + ) return false, nil } @@ -406,10 +416,11 @@ func (v *ValidatorInstance) shouldSubmitFinalitySignature(b *types.BlockInfo) (b } if power == 0 { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.GetBtcPkHex(), - "block_height": b.Height, - }).Debug("the validator does not have voting power, skip voting") + v.logger.Debug( + "the validator does not have voting power, skip voting", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("block_height", b.Height), + ) return false, nil } @@ -431,7 +442,7 @@ func (v *ValidatorInstance) checkLagging(currentBlock *types.BlockInfo) bool { // retrySubmitFinalitySignatureUntilBlockFinalized periodically tries to submit finality signature until success or the block is finalized // error will be returned if maximum retries have been reached or the query to the consumer chain fails func (v *ValidatorInstance) retrySubmitFinalitySignatureUntilBlockFinalized(targetBlock *types.BlockInfo) (*types.TxResponse, error) { - var failedCycles uint64 + var failedCycles uint32 // we break the for loop if the block is finalized or the signature is successfully submitted // error will be returned if maximum retries have been reached or the query to the consumer chain fails @@ -442,14 +453,16 @@ func (v *ValidatorInstance) retrySubmitFinalitySignatureUntilBlockFinalized(targ if clientcontroller.IsUnrecoverable(err) { return nil, err } - v.logger.WithFields(logrus.Fields{ - "currFailures": failedCycles, - "target_block_height": targetBlock.Height, - "error": err, - }).Error("err submitting finality signature to the consumer chain") + v.logger.Debug( + "failed to submit finality signature to the consumer chain", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint32("current_failures", failedCycles), + zap.Uint64("target_block_height", targetBlock.Height), + zap.Error(err), + ) failedCycles += 1 - if failedCycles > v.cfg.MaxSubmissionRetries { + if failedCycles > uint32(v.cfg.MaxSubmissionRetries) { return nil, fmt.Errorf("reached max failed cycles with err: %w", err) } } else { @@ -464,15 +477,16 @@ func (v *ValidatorInstance) retrySubmitFinalitySignatureUntilBlockFinalized(targ return nil, fmt.Errorf("failed to query block finalization at height %v: %w", targetBlock.Height, err) } if finalized { - v.logger.WithFields(logrus.Fields{ - "btc_val_pk": v.GetBtcPkHex(), - "block_height": targetBlock.Height, - }).Debug("the block is already finalized, skip submission") + v.logger.Debug( + "the block is already finalized, skip submission", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("target_height", targetBlock.Height), + ) return nil, nil } case <-v.quit: - v.logger.Debugf("the validator instance %s is closing", v.GetBtcPkHex()) + v.logger.Debug("the validator instance is closing", zap.String("pk", v.GetBtcPkHex())) return nil, nil } } @@ -490,7 +504,7 @@ func (v *ValidatorInstance) checkBlockFinalization(height uint64) (bool, error) // retryCommitPubRandUntilBlockFinalized periodically tries to commit public rand until success or the block is finalized // error will be returned if maximum retries have been reached or the query to the consumer chain fails func (v *ValidatorInstance) retryCommitPubRandUntilBlockFinalized(targetBlock *types.BlockInfo) (*types.TxResponse, error) { - var failedCycles uint64 + var failedCycles uint32 // we break the for loop if the block is finalized or the public rand is successfully committed // error will be returned if maximum retries have been reached or the query to the consumer chain fails @@ -501,15 +515,16 @@ func (v *ValidatorInstance) retryCommitPubRandUntilBlockFinalized(targetBlock *t if clientcontroller.IsUnrecoverable(err) { return nil, err } - v.logger.WithFields(logrus.Fields{ - "btc_val_pk": v.GetBtcPkHex(), - "currFailures": failedCycles, - "target_block_height": targetBlock.Height, - "error": err, - }).Error("err committing public randomness to the consumer chain") + v.logger.Debug( + "failed to commit public randomness to the consumer chain", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint32("current_failures", failedCycles), + zap.Uint64("target_block_height", targetBlock.Height), + zap.Error(err), + ) failedCycles += 1 - if failedCycles > v.cfg.MaxSubmissionRetries { + if failedCycles > uint32(v.cfg.MaxSubmissionRetries) { return nil, fmt.Errorf("reached max failed cycles with err: %w", err) } } else { @@ -524,15 +539,16 @@ func (v *ValidatorInstance) retryCommitPubRandUntilBlockFinalized(targetBlock *t return nil, fmt.Errorf("failed to query block finalization at height %v: %w", targetBlock.Height, err) } if finalized { - v.logger.WithFields(logrus.Fields{ - "btc_val_pk": v.GetBtcPkHex(), - "block_height": targetBlock.Height, - }).Debug("the block is already finalized, skip submission") + v.logger.Debug( + "the block is already finalized, skip submission", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("target_height", targetBlock.Height), + ) return nil, nil } case <-v.quit: - v.logger.Debugf("the validator instance %s is closing", v.GetBtcPkHex()) + v.logger.Debug("the validator instance is closing", zap.String("pk", v.GetBtcPkHex())) return nil, nil } } @@ -553,11 +569,12 @@ func (v *ValidatorInstance) CommitPubRand(tipBlock *types.BlockInfo) (*types.TxR // we are running out of the randomness startHeight = lastCommittedHeight + 1 } else { - v.logger.WithFields(logrus.Fields{ - "btc_pk_hex": v.btcPk.MarshalHex(), - "last_committed_height": v.GetLastCommittedHeight(), - "current_block_height": tipBlock.Height, - }).Debug("the validator has sufficient public randomness, skip committing more") + v.logger.Debug( + "the validator has sufficient public randomness, skip committing more", + zap.String("pk", v.GetBtcPkHex()), + zap.Uint64("block_height", tipBlock.Height), + zap.Uint64("last_committed_height", v.GetLastCommittedHeight()), + ) return nil, nil } @@ -716,7 +733,7 @@ func (v *ValidatorInstance) TestSubmitFinalitySignatureAndExtractPrivKey(b *type for _, ev := range res.Events { if strings.Contains(ev.EventType, "EventSlashedBTCValidator") { evidenceStr := ev.Attributes["evidence"] - v.logger.Debugf("found slashing evidence %s", evidenceStr) + v.logger.Debug("found slashing evidence") var evidence ftypes.Evidence if err := jsonpb.UnmarshalString(evidenceStr, &evidence); err != nil { return nil, nil, fmt.Errorf("failed to decode evidence bytes to evidence: %s", err.Error()) @@ -774,11 +791,12 @@ func (v *ValidatorInstance) latestFinalizedBlocksWithRetry(count uint64) ([]*typ response = latestFinalisedBlock return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - v.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("Failed to query babylon for the latest finalised blocks") + v.logger.Debug( + "failed to query babylon for the latest finalised blocks", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return nil, err } @@ -798,11 +816,12 @@ func (v *ValidatorInstance) getLatestBlockWithRetry() (*types.BlockInfo, error) } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - v.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the consumer chain for the latest block") + v.logger.Debug( + "failed to query the consumer chain for the latest block", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return nil, err } @@ -823,11 +842,12 @@ func (v *ValidatorInstance) GetVotingPowerWithRetry(height uint64) (uint64, erro } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - v.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the voting power") + v.logger.Debug( + "failed to query the voting power", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return 0, err } @@ -848,11 +868,12 @@ func (v *ValidatorInstance) GetValidatorSlashedWithRetry() (bool, error) { } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - v.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the voting power") + v.logger.Debug( + "failed to query the validator", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return false, err } diff --git a/validator/service/validator_instance_test.go b/validator/service/validator_instance_test.go index ef245f4c972d3..96ceaee846e52 100644 --- a/validator/service/validator_instance_test.go +++ b/validator/service/validator_instance_test.go @@ -6,8 +6,8 @@ import ( "testing" "github.com/golang/mock/gomock" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/eotsmanager" @@ -104,7 +104,7 @@ func startValidatorAppWithRegisteredValidator(t *testing.T, r *rand.Rand, cc cli cfg.NumPubRand = uint64(25) cfg.ValidatorModeConfig.AutoChainScanningMode = false cfg.ValidatorModeConfig.StaticChainScanningStartHeight = startingHeight - logger := logrus.New() + logger := zap.NewNop() eotsCfg, err := valcfg.NewEOTSManagerConfigFromAppConfig(&cfg) require.NoError(t, err) em, err := eotsmanager.NewLocalEOTSManager(eotsCfg, logger) diff --git a/validator/service/validator_manager.go b/validator/service/validator_manager.go index 89249f1d7f67f..b6507cbd1e142 100644 --- a/validator/service/validator_manager.go +++ b/validator/service/validator_manager.go @@ -9,8 +9,8 @@ import ( "github.com/avast/retry-go/v4" bbntypes "github.com/babylonchain/babylon/types" btcstakingtypes "github.com/babylonchain/babylon/x/btcstaking/types" - "github.com/sirupsen/logrus" "go.uber.org/atomic" + "go.uber.org/zap" "github.com/babylonchain/btc-validator/clientcontroller" "github.com/babylonchain/btc-validator/eotsmanager" @@ -45,7 +45,7 @@ type ValidatorManager struct { config *valcfg.Config cc clientcontroller.ClientController em eotsmanager.EOTSManager - logger *logrus.Logger + logger *zap.Logger criticalErrChan chan *CriticalError @@ -56,7 +56,7 @@ func NewValidatorManager(vs *valstore.ValidatorStore, config *valcfg.Config, cc clientcontroller.ClientController, em eotsmanager.EOTSManager, - logger *logrus.Logger, + logger *zap.Logger, ) (*ValidatorManager, error) { return &ValidatorManager{ vals: make(map[string]*ValidatorInstance), @@ -88,14 +88,12 @@ func (vm *ValidatorManager) monitorCriticalErr() { } if errors.Is(criticalErr.err, btcstakingtypes.ErrBTCValAlreadySlashed) { vm.setValidatorSlashed(vi) - vm.logger.WithFields(logrus.Fields{ - "err": criticalErr, - }).Debug("the validator status has been slashed") + vm.logger.Debug("the validator has been slashed", + zap.String("pk", criticalErr.valBtcPk.MarshalHex())) continue } - vi.logger.WithFields(logrus.Fields{ - "err": criticalErr, - }).Fatal(instanceTerminatingMsg) + vi.logger.Fatal(instanceTerminatingMsg, + zap.String("pk", criticalErr.valBtcPk.MarshalHex()), zap.Error(criticalErr.err)) case <-vm.quit: return } @@ -125,9 +123,7 @@ func (vm *ValidatorManager) monitorStatusUpdate() { case <-statusUpdateTicker.C: latestBlock, err := vm.getLatestBlockWithRetry() if err != nil { - vm.logger.WithFields(logrus.Fields{ - "err": err, - }).Debug("failed to get the latest block") + vm.logger.Debug("failed to get the latest block", zap.Error(err)) continue } vals := vm.ListValidatorInstances() @@ -135,49 +131,54 @@ func (vm *ValidatorManager) monitorStatusUpdate() { oldStatus := v.GetStatus() power, err := v.GetVotingPowerWithRetry(latestBlock.Height) if err != nil { - vm.logger.WithFields(logrus.Fields{ - "err": err, - "val_btc_pk": v.GetBtcPkHex(), - "height": latestBlock.Height, - }).Debug("failed to get the voting power") + vm.logger.Debug( + "failed to get the voting power", + zap.String("val_btc_pk", v.GetBtcPkHex()), + zap.Uint64("height", latestBlock.Height), + zap.Error(err), + ) continue } // power > 0 (slashed_height must > 0), set status to ACTIVE if power > 0 { if oldStatus != proto.ValidatorStatus_ACTIVE { v.MustSetStatus(proto.ValidatorStatus_ACTIVE) - vm.logger.WithFields(logrus.Fields{ - "val_btc_pk": v.GetBtcPkHex(), - "old_status": oldStatus, - "power": power, - }).Debug("the validator status has changed to ACTIVE") + vm.logger.Debug( + "the validator status is changed to ACTIVE", + zap.String("val_btc_pk", v.GetBtcPkHex()), + zap.String("old_status", oldStatus.String()), + zap.Uint64("power", power), + ) } continue } slashed, err := v.GetValidatorSlashedWithRetry() if err != nil { - vm.logger.WithFields(logrus.Fields{ - "err": err, - "val_btc_pk": v.GetBtcPkHex(), - }).Debug("failed to get the slashed height") + vm.logger.Debug( + "failed to get the slashed height", + zap.String("val_btc_pk", v.GetBtcPkHex()), + zap.Error(err), + ) continue } // power == 0 and slashed == true, set status to SLASHED and stop and remove the validator instance if slashed { vm.setValidatorSlashed(v) - vm.logger.WithFields(logrus.Fields{ - "val_btc_pk": v.GetBtcPkHex(), - "old_status": oldStatus, - }).Debug("the validator status has been slashed") + vm.logger.Debug( + "the validator is slashed", + zap.String("val_btc_pk", v.GetBtcPkHex()), + zap.String("old_status", oldStatus.String()), + ) continue } // power == 0 and slashed_height == 0, change to INACTIVE if the current status is ACTIVE if oldStatus == proto.ValidatorStatus_ACTIVE { v.MustSetStatus(proto.ValidatorStatus_INACTIVE) - vm.logger.WithFields(logrus.Fields{ - "val_btc_pk": v.GetBtcPkHex(), - "old_status": oldStatus, - }).Debug("the validator status has changed to INACTIVE") + vm.logger.Debug( + "the validator status is changed to INACTIVE", + zap.String("val_btc_pk", v.GetBtcPkHex()), + zap.String("old_status", oldStatus.String()), + ) } } case <-vm.quit: @@ -321,11 +322,12 @@ func (vm *ValidatorManager) getLatestBlockWithRetry() (*types.BlockInfo, error) } return nil }, RtyAtt, RtyDel, RtyErr, retry.OnRetry(func(n uint, err error) { - vm.logger.WithFields(logrus.Fields{ - "attempt": n + 1, - "max_attempts": RtyAttNum, - "error": err, - }).Debug("failed to query the consumer chain for the latest block") + vm.logger.Debug( + "failed to query the consumer chain for the latest block", + zap.Uint("attempt", n+1), + zap.Uint("max_attempts", RtyAttNum), + zap.Error(err), + ) })); err != nil { return nil, err } diff --git a/validator/service/validator_manager_test.go b/validator/service/validator_manager_test.go index e2ac1da2a81b9..e791a587b0230 100644 --- a/validator/service/validator_manager_test.go +++ b/validator/service/validator_manager_test.go @@ -1,18 +1,20 @@ package service_test import ( - "github.com/babylonchain/btc-validator/keyring" "math/rand" "os" "strings" "testing" "time" + "go.uber.org/zap" + + "github.com/babylonchain/btc-validator/keyring" + "github.com/babylonchain/babylon/testutil/datagen" bbntypes "github.com/babylonchain/babylon/types" "github.com/cosmos/cosmos-sdk/crypto/keys/secp256k1" "github.com/golang/mock/gomock" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" "github.com/babylonchain/btc-validator/clientcontroller" @@ -93,7 +95,7 @@ func newValidatorManagerWithRegisteredValidator(t *testing.T, r *rand.Rand, cc c cfg.StatusUpdateInterval = 10 * time.Millisecond cfg.DatabaseConfig = testutil.GenDBConfig(r, t) cfg.BabylonConfig.KeyDirectory = t.TempDir() - logger := logrus.New() + logger := zap.NewNop() input := strings.NewReader("") kr, err := keyring.CreateKeyring(