upgrade log level and log message (#102)

This commit is contained in:
Liam 2022-06-19 10:59:09 +02:00 committed by GitHub
parent 1cac82825d
commit ac5096d692
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
9 changed files with 31 additions and 40 deletions

View file

@ -134,7 +134,7 @@ func (x *XDPoS_v2) Initial(chain consensus.ChainReader, header *types.Header) er
log.Info("[Initial] initial v2 related parameters") log.Info("[Initial] initial v2 related parameters")
if x.highestQuorumCert.ProposedBlockInfo.Hash != (common.Hash{}) { // already initialized if x.highestQuorumCert.ProposedBlockInfo.Hash != (common.Hash{}) { // already initialized
log.Error("[Initial] Already initialized", "x.highestQuorumCert.ProposedBlockInfo.Hash", x.highestQuorumCert.ProposedBlockInfo.Hash) log.Info("[Initial] Already initialized", "x.highestQuorumCert.ProposedBlockInfo.Hash", x.highestQuorumCert.ProposedBlockInfo.Hash)
return nil return nil
} }
@ -248,7 +248,7 @@ func (x *XDPoS_v2) Prepare(chain consensus.ChainReader, header *types.Header) er
x.lock.RUnlock() x.lock.RUnlock()
if header.ParentHash != highestQC.ProposedBlockInfo.Hash { if header.ParentHash != highestQC.ProposedBlockInfo.Hash {
log.Warn("[Prepare] parent hash and QC hash does not match", "blockNum", header.Number, "parentHash", header.ParentHash, "QCHash", highestQC.ProposedBlockInfo.Hash, "QCNumber", highestQC.ProposedBlockInfo.Number) log.Warn("[Prepare] parent hash and QC hash does not match", "blockNum", header.Number, "QCNumber", highestQC.ProposedBlockInfo.Number, "blockHash", header.ParentHash, "QCHash", highestQC.ProposedBlockInfo.Hash)
return consensus.ErrNotReadyToPropose return consensus.ErrNotReadyToPropose
} }
@ -618,9 +618,6 @@ func (x *XDPoS_v2) VerifyTimeoutMessage(chain consensus.ChainReader, timeoutMsg
/* /*
Entry point for handling timeout message to process below: Entry point for handling timeout message to process below:
1. checkRoundNumber()
2. Collect timeout
3. Once timeout pool reached threshold, it will trigger the call to the function "onTimeoutPoolThresholdReached"
*/ */
func (x *XDPoS_v2) TimeoutHandler(blockChainReader consensus.ChainReader, timeout *types.Timeout) error { func (x *XDPoS_v2) TimeoutHandler(blockChainReader consensus.ChainReader, timeout *types.Timeout) error {
x.lock.Lock() x.lock.Lock()
@ -635,13 +632,6 @@ func (x *XDPoS_v2) ProposedBlockHandler(chain consensus.ChainReader, blockHeader
x.lock.Lock() x.lock.Lock()
defer x.lock.Unlock() defer x.lock.Unlock()
/*
1. Verify QC
2. Generate blockInfo
3. processQC(): process the QC inside the proposed block
4. verifyVotingRule(): the proposed block's info is extracted into BlockInfo and verified for voting
5. sendVote()
*/
// Get QC and Round from Extra // Get QC and Round from Extra
quorumCert, round, _, err := x.getExtraFields(blockHeader) quorumCert, round, _, err := x.getExtraFields(blockHeader)
if err != nil { if err != nil {
@ -671,8 +661,6 @@ func (x *XDPoS_v2) ProposedBlockHandler(chain consensus.ChainReader, blockHeader
} }
if verified { if verified {
return x.sendVote(chain, blockInfo) return x.sendVote(chain, blockInfo)
} else {
log.Info("Failed to pass the voting rule verification", "ProposeBlockHash", blockInfo.Hash)
} }
return nil return nil
@ -792,8 +780,8 @@ func (x *XDPoS_v2) verifyQC(blockChainReader consensus.ChainReader, quorumCert *
epochSwitchNumber := epochInfo.EpochSwitchBlockInfo.Number.Uint64() epochSwitchNumber := epochInfo.EpochSwitchBlockInfo.Number.Uint64()
gapNumber := epochSwitchNumber - epochSwitchNumber%x.config.Epoch - x.config.Gap gapNumber := epochSwitchNumber - epochSwitchNumber%x.config.Epoch - x.config.Gap
if gapNumber != quorumCert.GapNumber { if gapNumber != quorumCert.GapNumber {
log.Error("[verifyQC] gap number mismatch", "BlockInfoHash", quorumCert.ProposedBlockInfo.Hash, "Gap", quorumCert.GapNumber, "GapShouldBe", gapNumber) log.Error("[verifyQC] QC gap number mismatch", "epochSwitchNumber", epochSwitchNumber, "BlockNum", quorumCert.ProposedBlockInfo.Number, "BlockInfoHash", quorumCert.ProposedBlockInfo.Hash, "Gap", quorumCert.GapNumber, "GapShouldBe", gapNumber)
return fmt.Errorf("gap number mismatch %v", quorumCert) return fmt.Errorf("gap number mismatch QC Gap %d, shouldBe %d", quorumCert.GapNumber, gapNumber)
} }
return x.VerifyBlockInfo(blockChainReader, quorumCert.ProposedBlockInfo, parentHeader) return x.VerifyBlockInfo(blockChainReader, quorumCert.ProposedBlockInfo, parentHeader)
@ -801,16 +789,17 @@ func (x *XDPoS_v2) verifyQC(blockChainReader consensus.ChainReader, quorumCert *
// Update local QC variables including highestQC & lockQuorumCert, as well as commit the blocks that satisfy the algorithm requirements // Update local QC variables including highestQC & lockQuorumCert, as well as commit the blocks that satisfy the algorithm requirements
func (x *XDPoS_v2) processQC(blockChainReader consensus.ChainReader, incomingQuorumCert *types.QuorumCert) error { func (x *XDPoS_v2) processQC(blockChainReader consensus.ChainReader, incomingQuorumCert *types.QuorumCert) error {
log.Trace("[ProcessQC][Before]", "HighQC", x.highestQuorumCert) log.Trace("[processQC][Before]", "HighQC", x.highestQuorumCert)
// 1. Update HighestQC // 1. Update HighestQC
if incomingQuorumCert.ProposedBlockInfo.Round > x.highestQuorumCert.ProposedBlockInfo.Round { if incomingQuorumCert.ProposedBlockInfo.Round > x.highestQuorumCert.ProposedBlockInfo.Round {
log.Debug("[processQC] update x.highestQuorumCert", "blockNum", incomingQuorumCert.ProposedBlockInfo.Number, "round", incomingQuorumCert.ProposedBlockInfo.Round, "hash", incomingQuorumCert.ProposedBlockInfo.Hash)
x.highestQuorumCert = incomingQuorumCert x.highestQuorumCert = incomingQuorumCert
} }
// 2. Get QC from header and update lockQuorumCert(lockQuorumCert is the parent of highestQC) // 2. Get QC from header and update lockQuorumCert(lockQuorumCert is the parent of highestQC)
proposedBlockHeader := blockChainReader.GetHeaderByHash(incomingQuorumCert.ProposedBlockInfo.Hash) proposedBlockHeader := blockChainReader.GetHeaderByHash(incomingQuorumCert.ProposedBlockInfo.Hash)
if proposedBlockHeader == nil { if proposedBlockHeader == nil {
log.Error("[processQC] Block not found using the QC", "quorumCert.ProposedBlockInfo.Hash", incomingQuorumCert.ProposedBlockInfo.Hash, "incomingQuorumCert.ProposedBlockInfo.Number", incomingQuorumCert.ProposedBlockInfo.Number) log.Error("[processQC] Block not found using the QC", "quorumCert.ProposedBlockInfo.Hash", incomingQuorumCert.ProposedBlockInfo.Hash, "incomingQuorumCert.ProposedBlockInfo.Number", incomingQuorumCert.ProposedBlockInfo.Number)
return fmt.Errorf("Block not found, number: %v, hash: %v", incomingQuorumCert.ProposedBlockInfo.Number, incomingQuorumCert.ProposedBlockInfo.Hash) return fmt.Errorf("block not found, number: %v, hash: %v", incomingQuorumCert.ProposedBlockInfo.Number, incomingQuorumCert.ProposedBlockInfo.Hash)
} }
if proposedBlockHeader.Number.Cmp(x.config.V2.SwitchBlock) > 0 { if proposedBlockHeader.Number.Cmp(x.config.V2.SwitchBlock) > 0 {
// Extra field contain parent information // Extra field contain parent information
@ -834,7 +823,7 @@ func (x *XDPoS_v2) processQC(blockChainReader consensus.ChainReader, incomingQuo
if incomingQuorumCert.ProposedBlockInfo.Round >= x.currentRound { if incomingQuorumCert.ProposedBlockInfo.Round >= x.currentRound {
x.setNewRound(blockChainReader, incomingQuorumCert.ProposedBlockInfo.Round+1) x.setNewRound(blockChainReader, incomingQuorumCert.ProposedBlockInfo.Round+1)
} }
log.Trace("[ProcessQC][After]", "HighQC", x.highestQuorumCert) log.Trace("[processQC][After]", "HighQC", x.highestQuorumCert)
return nil return nil
} }

View file

@ -135,6 +135,6 @@ func (x *XDPoS_v2) IsEpochSwitch(header *types.Header) (bool, uint64, error) {
log.Info("[IsEpochSwitch] true, parent equals V2.SwitchBlock", "round", round, "number", header.Number.Uint64(), "hash", header.Hash()) log.Info("[IsEpochSwitch] true, parent equals V2.SwitchBlock", "round", round, "number", header.Number.Uint64(), "hash", header.Hash())
return true, epochNum, nil return true, epochNum, nil
} }
log.Info("[IsEpochSwitch]", "is", parentRound < epochStartRound, "parentRound", parentRound, "round", round, "number", header.Number.Uint64(), "epochNum", epochNum, "hash", header.Hash()) log.Debug("[IsEpochSwitch]", "is", parentRound < epochStartRound, "parentRound", parentRound, "round", round, "number", header.Number.Uint64(), "epochNum", epochNum, "hash", header.Hash())
return parentRound < epochStartRound, epochNum, nil return parentRound < epochStartRound, epochNum, nil
} }

View file

@ -42,20 +42,20 @@ func (x *XDPoS_v2) yourturn(chain consensus.ChainReader, round types.Round, pare
curIndex := utils.Position(masterNodes, signer) curIndex := utils.Position(masterNodes, signer)
if curIndex == -1 { if curIndex == -1 {
log.Warn("[yourturn] Not authorised signer", "MN", masterNodes, "Hash", parent.Hash(), "signer", signer) log.Warn("[yourturn] I am not in masternodes list", "Hash", parent.Hash(), "signer", signer)
return false, nil return false, nil
} }
for i, s := range masterNodes { for i, s := range masterNodes {
log.Warn("[yourturn] Masternode:", "index", i, "address", s.String(), "parentBlockNum", parent.Number) log.Debug("[yourturn] Masternode:", "index", i, "address", s.String(), "parentBlockNum", parent.Number)
} }
leaderIndex := uint64(round) % x.config.Epoch % uint64(len(masterNodes)) leaderIndex := uint64(round) % x.config.Epoch % uint64(len(masterNodes))
if masterNodes[leaderIndex] != signer { if masterNodes[leaderIndex] != signer {
log.Warn("[yourturn] Not my turn", "curIndex", curIndex, "leaderIndex", leaderIndex, "Hash", parent.Hash().Hex(), "masterNodes[leaderIndex]", masterNodes[leaderIndex], "signer", signer) log.Info("[yourturn] Not my turn", "curIndex", curIndex, "leaderIndex", leaderIndex, "Hash", parent.Hash().Hex(), "masterNodes[leaderIndex]", masterNodes[leaderIndex], "signer", signer)
return false, nil return false, nil
} }
log.Debug("[yourturn] Yes, it's my turn based on parent block", "ParentHash", parent.Hash().Hex(), "ParentBlockNumber", parent.Number.Uint64()) log.Info("[yourturn] Yes, it's my turn based on parent block", "ParentHash", parent.Hash().Hex(), "ParentBlockNumber", parent.Number.Uint64())
return true, nil return true, nil
} }

View file

@ -15,7 +15,7 @@ import (
) )
func (x *XDPoS_v2) timeoutHandler(blockChainReader consensus.ChainReader, timeout *types.Timeout) error { func (x *XDPoS_v2) timeoutHandler(blockChainReader consensus.ChainReader, timeout *types.Timeout) error {
// 1. checkRoundNumber // checkRoundNumber
if timeout.Round != x.currentRound { if timeout.Round != x.currentRound {
return &utils.ErrIncomingMessageRoundNotEqualCurrentRound{ return &utils.ErrIncomingMessageRoundNotEqualCurrentRound{
Type: "timeout", Type: "timeout",

View file

@ -55,7 +55,7 @@ func (x *XDPoS_v2) sendVote(chainReader consensus.ChainReader, blockInfo *types.
func (x *XDPoS_v2) voteHandler(chain consensus.ChainReader, voteMsg *types.Vote) error { func (x *XDPoS_v2) voteHandler(chain consensus.ChainReader, voteMsg *types.Vote) error {
// 1. checkRoundNumber // checkRoundNumber
if (voteMsg.ProposedBlockInfo.Round != x.currentRound) && (voteMsg.ProposedBlockInfo.Round != x.currentRound+1) { if (voteMsg.ProposedBlockInfo.Round != x.currentRound) && (voteMsg.ProposedBlockInfo.Round != x.currentRound+1) {
return &utils.ErrIncomingMessageRoundTooFarFromCurrentRound{ return &utils.ErrIncomingMessageRoundTooFarFromCurrentRound{
Type: "vote", Type: "vote",
@ -73,7 +73,7 @@ func (x *XDPoS_v2) voteHandler(chain consensus.ChainReader, voteMsg *types.Vote)
// Check if the block already exist, otherwise we try luck with the next vote // Check if the block already exist, otherwise we try luck with the next vote
proposedBlockHeader := chain.GetHeaderByHash(voteMsg.ProposedBlockInfo.Hash) proposedBlockHeader := chain.GetHeaderByHash(voteMsg.ProposedBlockInfo.Hash)
if proposedBlockHeader == nil { if proposedBlockHeader == nil {
log.Warn("[voteHandler] The proposed block from vote message does not exist yet, wait for the next vote to try again", "Hash", voteMsg.ProposedBlockInfo.Hash, "Round", voteMsg.ProposedBlockInfo.Round) log.Warn("[voteHandler] The proposed block from vote message does not exist yet, wait for the next vote to try again", "blockNum", voteMsg.ProposedBlockInfo.Number, "Hash", voteMsg.ProposedBlockInfo.Hash, "Round", voteMsg.ProposedBlockInfo.Round)
return nil return nil
} }
@ -152,6 +152,7 @@ func (x *XDPoS_v2) onVotePoolThresholdReached(chain consensus.ChainReader, poole
func (x *XDPoS_v2) verifyVotingRule(blockChainReader consensus.ChainReader, blockInfo *types.BlockInfo, quorumCert *types.QuorumCert) (bool, error) { func (x *XDPoS_v2) verifyVotingRule(blockChainReader consensus.ChainReader, blockInfo *types.BlockInfo, quorumCert *types.QuorumCert) (bool, error) {
// Make sure this node has not voted for this round. // Make sure this node has not voted for this round.
if x.currentRound <= x.highestVotedRound { if x.currentRound <= x.highestVotedRound {
log.Warn("Failed to pass the voting rule verification, currentRound is not large then highestVoteRound", "x.currentRound", x.currentRound, "x.highestVotedRound", x.highestVotedRound)
return false, nil return false, nil
} }
/* /*
@ -161,6 +162,7 @@ func (x *XDPoS_v2) verifyVotingRule(blockChainReader consensus.ChainReader, bloc
header's QC's ProposedBlockInfo.Round > lockQuorumCert's ProposedBlockInfo.Round header's QC's ProposedBlockInfo.Round > lockQuorumCert's ProposedBlockInfo.Round
*/ */
if blockInfo.Round != x.currentRound { if blockInfo.Round != x.currentRound {
log.Warn("Failed to pass the voting rule verification, blockRound is not equal currentRound", "x.currentRound", x.currentRound, "blockInfo.Round", blockInfo.Round)
return false, nil return false, nil
} }
// XDPoS v1.0 switch to v2.0, the proposed block can always pass voting rule // XDPoS v1.0 switch to v2.0, the proposed block can always pass voting rule
@ -174,13 +176,16 @@ func (x *XDPoS_v2) verifyVotingRule(blockChainReader consensus.ChainReader, bloc
isExtended, err := x.isExtendingFromAncestor(blockChainReader, blockInfo, x.lockQuorumCert.ProposedBlockInfo) isExtended, err := x.isExtendingFromAncestor(blockChainReader, blockInfo, x.lockQuorumCert.ProposedBlockInfo)
if err != nil { if err != nil {
log.Error("Failed to pass the voting rule verification, error on isExtendingFromAncestor", "err", err, "blockInfo", blockInfo, "x.lockQuorumCert.ProposedBlockInfo", x.lockQuorumCert.ProposedBlockInfo)
return false, err return false, err
} }
if isExtended {
return true, nil if !isExtended {
log.Warn("Failed to pass the voting rule verification, block is not extended from ancestor", "blockInfo", blockInfo, "x.lockQuorumCert.ProposedBlockInfo", x.lockQuorumCert.ProposedBlockInfo)
return false, nil
} }
return false, nil return true, nil
} }
func (x *XDPoS_v2) isExtendingFromAncestor(blockChainReader consensus.ChainReader, currentBlock *types.BlockInfo, ancestorBlock *types.BlockInfo) (bool, error) { func (x *XDPoS_v2) isExtendingFromAncestor(blockChainReader consensus.ChainReader, currentBlock *types.BlockInfo, ancestorBlock *types.BlockInfo) (bool, error) {

View file

@ -507,7 +507,7 @@ func (s *Ethereum) StartStaking(local bool) error {
if XDPoS, ok := s.engine.(*XDPoS.XDPoS); ok { if XDPoS, ok := s.engine.(*XDPoS.XDPoS); ok {
wallet, err := s.accountManager.Find(accounts.Account{Address: eb}) wallet, err := s.accountManager.Find(accounts.Account{Address: eb})
if wallet == nil || err != nil { if wallet == nil || err != nil {
log.Error("Etherbase account unavailable locally", "err", err, "address", eb.Hex()) log.Error("Etherbase account unavailable locally", "address", eb, "err", err)
return fmt.Errorf("signer missing: %v", err) return fmt.Errorf("signer missing: %v", err)
} }
XDPoS.Authorize(eb, wallet.SignHash) XDPoS.Authorize(eb, wallet.SignHash)

View file

@ -711,7 +711,7 @@ func (f *Fetcher) insert(peer string, block *types.Block) {
goto again goto again
default: default:
// Something went very wrong, drop the peer // Something went very wrong, drop the peer
log.Debug("Propagated block verification failed", "peer", peer, "number", block.Number(), "hash", hash, "err", err) log.Warn("Propagated block verification failed", "peer", peer, "number", block.Number(), "hash", hash, "err", err)
f.dropPeer(peer) f.dropPeer(peer)
return return
} }

View file

@ -958,8 +958,7 @@ func (pm *ProtocolManager) BroadcastVote(vote *types.Vote) {
for _, peer := range peers { for _, peer := range peers {
err := peer.SendVote(vote) err := peer.SendVote(vote)
if err != nil { if err != nil {
log.Error("[BroadcastVote] Fail to broadcast vote message", "NumberOfPeers", len(peers), "peerId", peer.id, "vote", vote, "Error", err) log.Error("[BroadcastVote] Fail to broadcast vote message", "peerId", peer.id, "version", peer.version, "blockNum", vote.ProposedBlockInfo.Number, "err", err)
log.Error("[BroadcastVote] Remove Peer", "id", peer.id, "version", peer.version)
pm.removePeer(peer.id) pm.removePeer(peer.id)
} }
} }
@ -976,8 +975,7 @@ func (pm *ProtocolManager) BroadcastTimeout(timeout *types.Timeout) {
for _, peer := range peers { for _, peer := range peers {
err := peer.SendTimeout(timeout) err := peer.SendTimeout(timeout)
if err != nil { if err != nil {
log.Error("[BroadcastTimeout] Fail to broadcast timeout message", "NumberOfPeers", len(peers), "peerId", peer.id, "timeout", timeout, "Error", err) log.Error("[BroadcastTimeout] Fail to broadcast timeout message, remove peer", "peerId", peer.id, "version", peer.version, "timeout", timeout, "err", err)
log.Error("[BroadcastTimeout] Remove Peer", "id", peer.id, "version", peer.version)
pm.removePeer(peer.id) pm.removePeer(peer.id)
} }
} }
@ -994,8 +992,7 @@ func (pm *ProtocolManager) BroadcastSyncInfo(syncInfo *types.SyncInfo) {
for _, peer := range peers { for _, peer := range peers {
err := peer.SendSyncInfo(syncInfo) err := peer.SendSyncInfo(syncInfo)
if err != nil { if err != nil {
log.Error("[BroadcastSyncInfo] Fail to broadcast syncInfo message", "NumberOfPeers", len(peers), "peerId", peer.id, "syncInfo", syncInfo, "Error", err) log.Error("[BroadcastSyncInfo] Fail to broadcast syncInfo message, remove peer", "peerId", peer.id, "version", peer.version, "syncInfo", syncInfo, "err", err)
log.Error("[BroadcastSyncInfo] Remove Peer", "id", peer.id, "version", peer.version)
pm.removePeer(peer.id) pm.removePeer(peer.id)
} }
} }

View file

@ -52,9 +52,9 @@ var (
SwitchBlock: big.NewInt(7218000), SwitchBlock: big.NewInt(7218000),
CertThreshold: 6, CertThreshold: 6,
TimeoutSyncThreshold: 5, TimeoutSyncThreshold: 5,
TimeoutPeriod: 50, TimeoutPeriod: 10,
WaitPeriod: 2, WaitPeriod: 2,
MinePeriod: 10, MinePeriod: 2,
} }
// XDPoSChain mainnet config // XDPoSChain mainnet config