diff --git a/consensus/XDPoS/engines/engine_v2/engine.go b/consensus/XDPoS/engines/engine_v2/engine.go index 63a659ffb8..c009d508f1 100644 --- a/consensus/XDPoS/engines/engine_v2/engine.go +++ b/consensus/XDPoS/engines/engine_v2/engine.go @@ -134,7 +134,7 @@ func (x *XDPoS_v2) Initial(chain consensus.ChainReader, header *types.Header) er log.Info("[Initial] initial v2 related parameters") 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 } @@ -248,7 +248,7 @@ func (x *XDPoS_v2) Prepare(chain consensus.ChainReader, header *types.Header) er x.lock.RUnlock() 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 } @@ -618,9 +618,6 @@ func (x *XDPoS_v2) VerifyTimeoutMessage(chain consensus.ChainReader, timeoutMsg /* 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 { x.lock.Lock() @@ -635,13 +632,6 @@ func (x *XDPoS_v2) ProposedBlockHandler(chain consensus.ChainReader, blockHeader x.lock.Lock() 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 quorumCert, round, _, err := x.getExtraFields(blockHeader) if err != nil { @@ -671,8 +661,6 @@ func (x *XDPoS_v2) ProposedBlockHandler(chain consensus.ChainReader, blockHeader } if verified { return x.sendVote(chain, blockInfo) - } else { - log.Info("Failed to pass the voting rule verification", "ProposeBlockHash", blockInfo.Hash) } return nil @@ -792,8 +780,8 @@ func (x *XDPoS_v2) verifyQC(blockChainReader consensus.ChainReader, quorumCert * epochSwitchNumber := epochInfo.EpochSwitchBlockInfo.Number.Uint64() gapNumber := epochSwitchNumber - epochSwitchNumber%x.config.Epoch - x.config.Gap if gapNumber != quorumCert.GapNumber { - log.Error("[verifyQC] gap number mismatch", "BlockInfoHash", quorumCert.ProposedBlockInfo.Hash, "Gap", quorumCert.GapNumber, "GapShouldBe", gapNumber) - return fmt.Errorf("gap number mismatch %v", quorumCert) + 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 QC Gap %d, shouldBe %d", quorumCert.GapNumber, gapNumber) } 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 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 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 } // 2. Get QC from header and update lockQuorumCert(lockQuorumCert is the parent of highestQC) proposedBlockHeader := blockChainReader.GetHeaderByHash(incomingQuorumCert.ProposedBlockInfo.Hash) if proposedBlockHeader == nil { 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 { // Extra field contain parent information @@ -834,7 +823,7 @@ func (x *XDPoS_v2) processQC(blockChainReader consensus.ChainReader, incomingQuo if incomingQuorumCert.ProposedBlockInfo.Round >= x.currentRound { x.setNewRound(blockChainReader, incomingQuorumCert.ProposedBlockInfo.Round+1) } - log.Trace("[ProcessQC][After]", "HighQC", x.highestQuorumCert) + log.Trace("[processQC][After]", "HighQC", x.highestQuorumCert) return nil } diff --git a/consensus/XDPoS/engines/engine_v2/epochSwitch.go b/consensus/XDPoS/engines/engine_v2/epochSwitch.go index 1adaa34649..66feda0617 100644 --- a/consensus/XDPoS/engines/engine_v2/epochSwitch.go +++ b/consensus/XDPoS/engines/engine_v2/epochSwitch.go @@ -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()) 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 } diff --git a/consensus/XDPoS/engines/engine_v2/mining.go b/consensus/XDPoS/engines/engine_v2/mining.go index fdc1325f4a..951d0eaa14 100644 --- a/consensus/XDPoS/engines/engine_v2/mining.go +++ b/consensus/XDPoS/engines/engine_v2/mining.go @@ -42,20 +42,20 @@ func (x *XDPoS_v2) yourturn(chain consensus.ChainReader, round types.Round, pare curIndex := utils.Position(masterNodes, signer) 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 } 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)) 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 } - 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 } diff --git a/consensus/XDPoS/engines/engine_v2/timeout.go b/consensus/XDPoS/engines/engine_v2/timeout.go index 7ec9768130..9dacc773df 100644 --- a/consensus/XDPoS/engines/engine_v2/timeout.go +++ b/consensus/XDPoS/engines/engine_v2/timeout.go @@ -15,7 +15,7 @@ import ( ) func (x *XDPoS_v2) timeoutHandler(blockChainReader consensus.ChainReader, timeout *types.Timeout) error { - // 1. checkRoundNumber + // checkRoundNumber if timeout.Round != x.currentRound { return &utils.ErrIncomingMessageRoundNotEqualCurrentRound{ Type: "timeout", diff --git a/consensus/XDPoS/engines/engine_v2/vote.go b/consensus/XDPoS/engines/engine_v2/vote.go index f044b32329..37ea91a61a 100644 --- a/consensus/XDPoS/engines/engine_v2/vote.go +++ b/consensus/XDPoS/engines/engine_v2/vote.go @@ -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 { - // 1. checkRoundNumber + // checkRoundNumber if (voteMsg.ProposedBlockInfo.Round != x.currentRound) && (voteMsg.ProposedBlockInfo.Round != x.currentRound+1) { return &utils.ErrIncomingMessageRoundTooFarFromCurrentRound{ 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 proposedBlockHeader := chain.GetHeaderByHash(voteMsg.ProposedBlockInfo.Hash) 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 } @@ -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) { // Make sure this node has not voted for this round. 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 } /* @@ -161,6 +162,7 @@ func (x *XDPoS_v2) verifyVotingRule(blockChainReader consensus.ChainReader, bloc header's QC's ProposedBlockInfo.Round > lockQuorumCert's ProposedBlockInfo.Round */ 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 } // 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) 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 } - 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) { diff --git a/eth/backend.go b/eth/backend.go index 9fe46f6e48..b08219cf3e 100644 --- a/eth/backend.go +++ b/eth/backend.go @@ -507,7 +507,7 @@ func (s *Ethereum) StartStaking(local bool) error { if XDPoS, ok := s.engine.(*XDPoS.XDPoS); ok { wallet, err := s.accountManager.Find(accounts.Account{Address: eb}) 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) } XDPoS.Authorize(eb, wallet.SignHash) diff --git a/eth/fetcher/fetcher.go b/eth/fetcher/fetcher.go index ea970ecfaf..045ff31b21 100644 --- a/eth/fetcher/fetcher.go +++ b/eth/fetcher/fetcher.go @@ -711,7 +711,7 @@ func (f *Fetcher) insert(peer string, block *types.Block) { goto again default: // 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) return } diff --git a/eth/handler.go b/eth/handler.go index e920555e68..f0411bc420 100644 --- a/eth/handler.go +++ b/eth/handler.go @@ -958,8 +958,7 @@ func (pm *ProtocolManager) BroadcastVote(vote *types.Vote) { for _, peer := range peers { err := peer.SendVote(vote) if err != nil { - log.Error("[BroadcastVote] Fail to broadcast vote message", "NumberOfPeers", len(peers), "peerId", peer.id, "vote", vote, "Error", err) - log.Error("[BroadcastVote] Remove Peer", "id", peer.id, "version", peer.version) + log.Error("[BroadcastVote] Fail to broadcast vote message", "peerId", peer.id, "version", peer.version, "blockNum", vote.ProposedBlockInfo.Number, "err", err) pm.removePeer(peer.id) } } @@ -976,8 +975,7 @@ func (pm *ProtocolManager) BroadcastTimeout(timeout *types.Timeout) { for _, peer := range peers { err := peer.SendTimeout(timeout) if err != nil { - log.Error("[BroadcastTimeout] Fail to broadcast timeout message", "NumberOfPeers", len(peers), "peerId", peer.id, "timeout", timeout, "Error", err) - log.Error("[BroadcastTimeout] Remove Peer", "id", peer.id, "version", peer.version) + log.Error("[BroadcastTimeout] Fail to broadcast timeout message, remove peer", "peerId", peer.id, "version", peer.version, "timeout", timeout, "err", err) pm.removePeer(peer.id) } } @@ -994,8 +992,7 @@ func (pm *ProtocolManager) BroadcastSyncInfo(syncInfo *types.SyncInfo) { for _, peer := range peers { err := peer.SendSyncInfo(syncInfo) if err != nil { - log.Error("[BroadcastSyncInfo] Fail to broadcast syncInfo message", "NumberOfPeers", len(peers), "peerId", peer.id, "syncInfo", syncInfo, "Error", err) - log.Error("[BroadcastSyncInfo] Remove Peer", "id", peer.id, "version", peer.version) + log.Error("[BroadcastSyncInfo] Fail to broadcast syncInfo message, remove peer", "peerId", peer.id, "version", peer.version, "syncInfo", syncInfo, "err", err) pm.removePeer(peer.id) } } diff --git a/params/config.go b/params/config.go index d7b1c031a8..220d6ca29a 100644 --- a/params/config.go +++ b/params/config.go @@ -52,9 +52,9 @@ var ( SwitchBlock: big.NewInt(7218000), CertThreshold: 6, TimeoutSyncThreshold: 5, - TimeoutPeriod: 50, + TimeoutPeriod: 10, WaitPeriod: 2, - MinePeriod: 10, + MinePeriod: 2, } // XDPoSChain mainnet config