From e85c1f306462c9816494d04c161778b3a6db984a Mon Sep 17 00:00:00 2001 From: Rongjian Lan Date: Tue, 19 May 2020 20:44:33 -0700 Subject: [PATCH] Fix log levels (#3058) --- api/service/syncing/downloader/client.go | 2 +- api/service/syncing/syncing.go | 2 +- consensus/consensus_service.go | 2 +- consensus/leader.go | 10 +++++----- consensus/threshold.go | 2 +- consensus/validator.go | 4 ++-- core/offchain.go | 4 +--- node/node.go | 4 +++- node/node_cross_link.go | 4 ++-- node/node_cross_shard.go | 4 ++-- node/node_explorer.go | 8 +++++--- node/node_newblock.go | 6 +++--- 12 files changed, 27 insertions(+), 25 deletions(-) diff --git a/api/service/syncing/downloader/client.go b/api/service/syncing/downloader/client.go index 17c90171c..7e44e857a 100644 --- a/api/service/syncing/downloader/client.go +++ b/api/service/syncing/downloader/client.go @@ -27,7 +27,7 @@ func ClientSetup(ip, port string) *Client { utils.Logger().Error().Err(err).Str("ip", ip).Msg("[SYNC] client.go:ClientSetup fail to dial") return nil } - utils.Logger().Info().Str("ip", ip).Msg("[SYNC] grpc connect successfully") + utils.Logger().Debug().Str("ip", ip).Msg("[SYNC] grpc connect successfully") client.dlClient = pb.NewDownloaderClient(client.conn) return &client } diff --git a/api/service/syncing/syncing.go b/api/service/syncing/syncing.go index e1fe91e6f..8a04c4503 100644 --- a/api/service/syncing/syncing.go +++ b/api/service/syncing/syncing.go @@ -780,7 +780,7 @@ func (ss *StateSync) SyncLoop(bc *core.BlockChain, worker *worker.Worker, isBeac isBeacon, bc.ShardID(), otherHeight, currentHeight) return } - utils.Logger().Debug(). + utils.Logger().Info(). Msgf("[SYNC] Node is OUT OF SYNC (isBeacon: %t, ShardID: %d, otherHeight: %d, currentHeight: %d)", isBeacon, bc.ShardID(), otherHeight, currentHeight) diff --git a/consensus/consensus_service.go b/consensus/consensus_service.go index c6047a061..b90851933 100644 --- a/consensus/consensus_service.go +++ b/consensus/consensus_service.go @@ -93,7 +93,7 @@ func (consensus *Consensus) UpdatePublicKeys(pubKeys []*bls.PublicKey) int64 { consensus.Decider.UpdateParticipants(pubKeys) utils.Logger().Info().Msg("My Committee updated") for i := range pubKeys { - utils.Logger().Info(). + utils.Logger().Debug(). Int("index", i). Str("BLSPubKey", pubKeys[i].SerializeToHexStr()). Msg("Member") diff --git a/consensus/leader.go b/consensus/leader.go index 0c002df84..cba41c2ca 100644 --- a/consensus/leader.go +++ b/consensus/leader.go @@ -164,7 +164,7 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) { logger = logger.With(). Int64("NumReceivedSoFar", consensus.Decider.SignersCount(quorum.Prepare)). Int64("PublicKeys", consensus.Decider.ParticipantsCount()).Logger() - logger.Info().Msg("[OnPrepare] Received New Prepare Signature") + logger.Debug().Msg("[OnPrepare] Received New Prepare Signature") if _, err := consensus.Decider.SubmitVote( quorum.Prepare, validatorPubKey, &sign, recvMsg.BlockHash, @@ -224,7 +224,7 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) { // Must have the corresponding block to verify committed message. blockObj := consensus.FBFTLog.GetBlockByHash(recvMsg.BlockHash) if blockObj == nil { - consensus.getLogger().Debug(). + consensus.getLogger().Info(). Uint64("blockNum", recvMsg.BlockNum). Uint64("viewID", recvMsg.ViewID). Str("blockHash", recvMsg.BlockHash.Hex()). @@ -246,7 +246,7 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) { logger = logger.With(). Int64("numReceivedSoFar", consensus.Decider.SignersCount(quorum.Commit)). Logger() - logger.Info().Msg("[OnCommit] Received new commit message") + logger.Debug().Msg("[OnCommit] Received new commit message") if _, err := consensus.Decider.SubmitVote( quorum.Commit, validatorPubKey, @@ -266,14 +266,14 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) { if !quorumWasMet && quorumIsMet { logger.Info().Msg("[OnCommit] 2/3 Enough commits received") go func(viewID uint64) { - consensus.getLogger().Debug().Msg("[OnCommit] Starting Grace Period") + consensus.getLogger().Info().Msg("[OnCommit] Starting Grace Period") // Always wait for 2 seconds as minimum grace period time.Sleep(2 * time.Second) if n := time.Now(); n.Before(consensus.NextBlockDue) { // Sleep to wait for the full block time time.Sleep(consensus.NextBlockDue.Sub(n)) } - logger.Debug().Msg("[OnCommit] Commit Grace Period Ended") + logger.Info().Msg("[OnCommit] Commit Grace Period Ended") consensus.commitFinishChan <- viewID }(consensus.viewID) diff --git a/consensus/threshold.go b/consensus/threshold.go index f0b223a3b..4c4367065 100644 --- a/consensus/threshold.go +++ b/consensus/threshold.go @@ -13,7 +13,7 @@ import ( func (consensus *Consensus) didReachPrepareQuorum() error { logger := utils.Logger() - logger.Debug().Msg("[OnPrepare] Received Enough Prepare Signatures") + logger.Info().Msg("[OnPrepare] Received Enough Prepare Signatures") leaderPriKey, err := consensus.GetConsensusLeaderPrivateKey() if err != nil { utils.Logger().Warn().Err(err).Msg("[OnPrepare] leader not found") diff --git a/consensus/validator.go b/consensus/validator.go index 70d2c01d9..f11e721b8 100644 --- a/consensus/validator.go +++ b/consensus/validator.go @@ -299,7 +299,7 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) { consensus.commitBitmap = mask if recvMsg.BlockNum-consensus.blockNum > consensusBlockNumBuffer { - consensus.getLogger().Debug().Uint64("MsgBlockNum", recvMsg.BlockNum).Msg("[OnCommitted] OUT OF SYNC") + consensus.getLogger().Info().Uint64("MsgBlockNum", recvMsg.BlockNum).Msg("[OnCommitted] OUT OF SYNC") go func() { select { case consensus.BlockNumLowChan <- struct{}{}: @@ -315,7 +315,7 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) { consensus.tryCatchup() if consensus.current.Mode() == ViewChanging { - consensus.getLogger().Debug().Msg("[OnCommitted] Still in ViewChanging mode, Exiting!!") + consensus.getLogger().Info().Msg("[OnCommitted] Still in ViewChanging mode, Exiting!!") return } diff --git a/core/offchain.go b/core/offchain.go index 85400151b..3302b4cf3 100644 --- a/core/offchain.go +++ b/core/offchain.go @@ -186,9 +186,7 @@ func (bc *BlockChain) CommitOffChainData( for i, c := uint32(0), shard.Schedule.InstanceForEpoch( epoch, ).NumShards(); i < c; i++ { - if err := bc.LastContinuousCrossLink(batch, i); err != nil { - utils.Logger().Info().Msg("Could not roll up last continuous crosslink") - } + bc.LastContinuousCrossLink(batch, i) } } diff --git a/node/node.go b/node/node.go index bda6054a7..7660951ac 100644 --- a/node/node.go +++ b/node/node.go @@ -225,10 +225,11 @@ func (node *Node) addPendingTransactions(newTxs types.Transactions) []error { pendingCount, queueCount := node.TxPool.Stats() utils.Logger().Info(). + Interface("err", errs). Int("length of newTxs", len(newTxs)). Int("totalPending", pendingCount). Int("totalQueued", queueCount). - Msg("Got more transactions") + Msg("[addPendingTransactions] Adding more transactions") return errs } @@ -276,6 +277,7 @@ func (node *Node) AddPendingTransaction(newTx *types.Transaction) error { errs := node.addPendingTransactions(types.Transactions{newTx}) for i := range errs { if errs[i] != nil { + utils.Logger().Info().Err(errs[i]).Msg("[AddPendingTransaction] Failed adding new transaction") return errs[i] } } diff --git a/node/node_cross_link.go b/node/node_cross_link.go index 0d076524e..55e274117 100644 --- a/node/node_cross_link.go +++ b/node/node_cross_link.go @@ -96,7 +96,7 @@ func (node *Node) ProcessCrossLinkMessage(msgPayload []byte) { } if _, ok := existingCLs[cl.Hash()]; ok { - utils.Logger().Err(err). + utils.Logger().Debug().Err(err). Msgf("[ProcessingCrossLink] Cross Link already exists in pending queue, pass. Beacon Epoch: %d, Block num: %d, Epoch: %d, shardID %d", node.Blockchain().CurrentHeader().Epoch(), cl.Number(), cl.Epoch(), cl.ShardID()) continue @@ -104,7 +104,7 @@ func (node *Node) ProcessCrossLinkMessage(msgPayload []byte) { exist, err := node.Blockchain().ReadCrossLink(cl.ShardID(), cl.Number().Uint64()) if err == nil && exist != nil { - utils.Logger().Err(err). + utils.Logger().Debug().Err(err). Msgf("[ProcessingCrossLink] Cross Link already exists, pass. Beacon Epoch: %d, Block num: %d, Epoch: %d, shardID %d", node.Blockchain().CurrentHeader().Epoch(), cl.Number(), cl.Epoch(), cl.ShardID()) continue } diff --git a/node/node_cross_shard.go b/node/node_cross_shard.go index 970ef0aa0..8738ecbb1 100644 --- a/node/node_cross_shard.go +++ b/node/node_cross_shard.go @@ -46,7 +46,7 @@ func (node *Node) BroadcastCXReceipts(newBlock *types.Block) { // BroadcastCXReceiptsWithShardID broadcasts cross shard receipts to given ToShardID func (node *Node) BroadcastCXReceiptsWithShardID(block *types.Block, commitSig []byte, commitBitmap []byte, toShardID uint32) { myShardID := node.Consensus.ShardID - utils.Logger().Info(). + utils.Logger().Debug(). Uint32("toShardID", toShardID). Uint32("myShardID", myShardID). Uint64("blockNum", block.NumberU64()). @@ -54,7 +54,7 @@ func (node *Node) BroadcastCXReceiptsWithShardID(block *types.Block, commitSig [ cxReceipts, err := node.Blockchain().ReadCXReceipts(toShardID, block.NumberU64(), block.Hash()) if err != nil || len(cxReceipts) == 0 { - utils.Logger().Info().Uint32("ToShardID", toShardID). + utils.Logger().Debug().Uint32("ToShardID", toShardID). Int("numCXReceipts", len(cxReceipts)). Msg("[CXMerkleProof] No receipts found for the destination shard") return diff --git a/node/node_explorer.go b/node/node_explorer.go index 574bf3fdc..88f94a650 100644 --- a/node/node_explorer.go +++ b/node/node_explorer.go @@ -118,7 +118,7 @@ func (node *Node) ExplorerMessageHandler(payload []byte) { // AddNewBlockForExplorer add new block for explorer. func (node *Node) AddNewBlockForExplorer(block *types.Block) { - utils.Logger().Debug().Uint64("blockHeight", block.NumberU64()).Msg("[Explorer] Adding new block for explorer node") + utils.Logger().Info().Uint64("blockHeight", block.NumberU64()).Msg("[Explorer] Adding new block for explorer node") if _, err := node.Blockchain().InsertChain([]*types.Block{block}, true); err == nil { if len(block.Header().ShardState()) > 0 { node.Consensus.UpdateConsensusInformation() @@ -165,7 +165,8 @@ func (node *Node) GetTransactionsHistory(address, txType, order string) ([]commo key := explorer.GetAddressKey(address) bytes, err := explorer.GetStorageInstance(node.SelfPeer.IP, node.SelfPeer.Port, false).GetDB().Get([]byte(key), nil) if err != nil { - utils.Logger().Error().Err(err).Msg("[Explorer] Cannot get storage db instance") + utils.Logger().Debug().Err(err). + Msgf("[Explorer] Error retrieving transaction history for address %s", address) return make([]common.Hash, 0), nil } if err = rlp.DecodeBytes(bytes, &addressData); err != nil { @@ -197,7 +198,8 @@ func (node *Node) GetStakingTransactionsHistory(address, txType, order string) ( key := explorer.GetAddressKey(address) bytes, err := explorer.GetStorageInstance(node.SelfPeer.IP, node.SelfPeer.Port, false).GetDB().Get([]byte(key), nil) if err != nil { - utils.Logger().Error().Err(err).Msg("[Explorer] Cannot get storage db instance") + utils.Logger().Debug().Err(err). + Msgf("[Explorer] Staking transaction history for address %s not found", address) return make([]common.Hash, 0), nil } if err = rlp.DecodeBytes(bytes, &addressData); err != nil { diff --git a/node/node_newblock.go b/node/node_newblock.go index 5e2b862e3..61668822b 100644 --- a/node/node_newblock.go +++ b/node/node_newblock.go @@ -45,7 +45,7 @@ func (node *Node) WaitForConsensusReadyV2(readySignal chan struct{}, stopChan ch for node.Consensus != nil && node.Consensus.IsLeader() { time.Sleep(SleepPeriod) - utils.Logger().Debug(). + utils.Logger().Info(). Uint64("blockNum", node.Blockchain().CurrentBlock().NumberU64()+1). Msg("PROPOSING NEW BLOCK ------------------------------------------------") @@ -56,7 +56,7 @@ func (node *Node) WaitForConsensusReadyV2(readySignal chan struct{}, stopChan ch err = node.Blockchain().Validator().ValidateHeader(newBlock, true) if err == nil { - utils.Logger().Debug(). + utils.Logger().Info(). Uint64("blockNum", newBlock.NumberU64()). Uint64("epoch", newBlock.Epoch().Uint64()). Uint64("viewID", newBlock.Header().ViewID().Uint64()). @@ -197,7 +197,7 @@ func (node *Node) proposeNewBlock() (*types.Block, error) { crossLinksToPropose = append(crossLinksToPropose, pending) } - utils.Logger().Debug(). + utils.Logger().Info(). Msgf("[proposeNewBlock] Proposed %d crosslinks from %d pending crosslinks", len(crossLinksToPropose), len(allPending), )