PoS_EVM
/
woop
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Change Byte Output in Zerolog to Hex

Browse Source
pull/1507/head
charleszqwang 5 years ago
parent c3f4cb9135
commit aa2e800575
9 changed files with 196 additions and 196 deletions
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Show Stats Download Patch File Download Diff File
  1. 6
      api/service/syncing/syncing.go
  2. 252
      consensus/consensus_v2.go
  3. 8
      consensus/consensus_viewchange_msg.go
  4. 110
      consensus/view_change.go
  5. 2
      core/blockchain.go
  6. 2
      core/rawdb/accessors_indexes.go
  7. 2
      core/rawdb/accessors_metadata.go
  8. 6
      drand/drand_leader.go
  9. 4
      node/node_handler.go

6
api/service/syncing/syncing.go
Unescape View File

@ -506,8 +506,8 @@ func (ss *StateSync) getMaxConsensusBlockFromParentHash(parentHash common.Hash)
maxFirstID, maxCount := GetHowManyMaxConsensus(candidateBlocks)
hash := candidateBlocks[maxFirstID].Hash()
utils.Logger().Debug().
Bytes("parentHash", parentHash[:]).
Bytes("hash", hash[:]).
Hex("parentHash", parentHash[:]).
Hex("hash", hash[:]).
Int("maxCount", maxCount).
Msg("[SYNC] Find block with matching parenthash")
return candidateBlocks[maxFirstID]
@ -662,7 +662,7 @@ func (ss *StateSync) RegisterNodeInfo() int {
err := peerConfig.registerToBroadcast(ss.selfPeerHash[:], ss.selfip, ss.selfport)
if err != nil {
logger.Debug().
Bytes("selfPeerHash", ss.selfPeerHash[:]).
Hex("selfPeerHash", ss.selfPeerHash[:]).
Msg("[SYNC] register failed to peer")
return
}

252
consensus/consensus_v2.go
Unescape View File

@ -44,7 +44,7 @@ func (consensus *Consensus) handleMessageUpdate(payload []byte) {
if msg.Type == msg_pb.MessageType_VIEWCHANGE || msg.Type == msg_pb.MessageType_NEWVIEW {
if msg.GetViewchange() != nil && msg.GetViewchange().ShardId != consensus.ShardID {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint32("myShardId", consensus.ShardID).
Uint32("receivedShardId", msg.GetViewchange().ShardId).
Msg("Received view change message from different shard")
@ -52,7 +52,7 @@ func (consensus *Consensus) handleMessageUpdate(payload []byte) {
}
} else {
if msg.GetConsensus() != nil && msg.GetConsensus().ShardId != consensus.ShardID {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint32("myShardId", consensus.ShardID).
Uint32("receivedShardId", msg.GetConsensus().ShardId).
Msg("Received consensus message from different shard")
@ -86,12 +86,12 @@ func (consensus *Consensus) announce(block *types.Block) {
// prepare message and broadcast to validators
encodedBlock, err := rlp.EncodeToBytes(block)
if err != nil {
consensus.getLogger().Debug().Msg("[Announce] Failed encoding block")
utils.Logger().Debug().Msg("[Announce] Failed encoding block")
return
}
encodedBlockHeader, err := rlp.EncodeToBytes(block.Header())
if err != nil {
consensus.getLogger().Debug().Msg("[Announce] Failed encoding block header")
utils.Logger().Debug().Msg("[Announce] Failed encoding block header")
return
}
@ -105,12 +105,12 @@ func (consensus *Consensus) announce(block *types.Block) {
_ = protobuf.Unmarshal(msgPayload, msg)
pbftMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[Announce] Unable to parse pbft message")
utils.Logger().Warn().Err(err).Msg("[Announce] Unable to parse pbft message")
return
}
consensus.PbftLog.AddMessage(pbftMsg)
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("MsgBlockHash", pbftMsg.BlockHash.Hex()).
Uint64("MsgViewID", pbftMsg.ViewID).
Uint64("MsgBlockNum", pbftMsg.BlockNum).
@ -120,24 +120,24 @@ func (consensus *Consensus) announce(block *types.Block) {
// Leader sign the block hash itself
consensus.prepareSigs[consensus.PubKey.SerializeToHexStr()] = consensus.priKey.SignHash(consensus.blockHash[:])
if err := consensus.prepareBitmap.SetKey(consensus.PubKey, true); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[Announce] Leader prepareBitmap SetKey failed")
utils.Logger().Warn().Err(err).Msg("[Announce] Leader prepareBitmap SetKey failed")
return
}
// Construct broadcast p2p message
if err := consensus.msgSender.SendWithRetry(consensus.blockNum, msg_pb.MessageType_ANNOUNCE, []p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend)); err != nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Str("groupID", string(p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID)))).
Msg("[Announce] Cannot send announce message")
} else {
consensus.getLogger().Info().
utils.Logger().Info().
Str("blockHash", block.Hash().Hex()).
Uint64("blockNum", block.NumberU64()).
Msg("[Announce] Sent Announce Message!!")
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Prepare.String()).
Msg("[Announce] Switching phase")
@ -145,31 +145,31 @@ func (consensus *Consensus) announce(block *types.Block) {
}
func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
consensus.getLogger().Debug().Msg("[OnAnnounce] Receive announce message")
utils.Logger().Debug().Msg("[OnAnnounce] Receive announce message")
if consensus.IsLeader() && consensus.mode.Mode() == Normal {
return
}
senderKey, err := consensus.verifySenderKey(msg)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnAnnounce] VerifySenderKey failed")
utils.Logger().Error().Err(err).Msg("[OnAnnounce] VerifySenderKey failed")
return
}
if !senderKey.IsEqual(consensus.LeaderPubKey) && consensus.mode.Mode() == Normal && !consensus.ignoreViewIDCheck {
consensus.getLogger().Warn().
utils.Logger().Warn().
Str("senderKey", senderKey.SerializeToHexStr()).
Str("leaderKey", consensus.LeaderPubKey.SerializeToHexStr()).
Msg("[OnAnnounce] SenderKey does not match leader PubKey")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnAnnounce] Failed to verify leader signature")
utils.Logger().Error().Err(err).Msg("[OnAnnounce] Failed to verify leader signature")
return
}
recvMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Error().
utils.Logger().Error().
Err(err).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnAnnounce] Unparseable leader message")
@ -181,7 +181,7 @@ func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
var headerObj types.Header
err = rlp.DecodeBytes(blockHeader, &headerObj)
if err != nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Err(err).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnAnnounce] Unparseable block header data")
@ -189,7 +189,7 @@ func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
}
if recvMsg.BlockNum < consensus.blockNum || recvMsg.BlockNum != headerObj.Number.Uint64() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
Uint64("hdrBlockNum", headerObj.Number.Uint64()).
@ -198,7 +198,7 @@ func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
}
if consensus.mode.Mode() == Normal {
if err = consensus.VerifyHeader(consensus.ChainReader, &headerObj, true); err != nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Err(err).
Str("inChain", consensus.ChainReader.CurrentHeader().Number.String()).
Str("MsgBlockNum", headerObj.Number.String()).
@ -210,18 +210,18 @@ func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
logMsgs := consensus.PbftLog.GetMessagesByTypeSeqView(msg_pb.MessageType_ANNOUNCE, recvMsg.BlockNum, recvMsg.ViewID)
if len(logMsgs) > 0 {
if logMsgs[0].BlockHash != recvMsg.BlockHash {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("leaderKey", consensus.LeaderPubKey.SerializeToHexStr()).
Msg("[OnAnnounce] Leader is malicious")
consensus.startViewChange(consensus.viewID + 1)
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("leaderKey", consensus.LeaderPubKey.SerializeToHexStr()).
Msg("[OnAnnounce] Announce message received again")
//return
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnAnnounce] Announce message Added")
@ -234,13 +234,13 @@ func (consensus *Consensus) onAnnounce(msg *msg_pb.Message) {
// we have already added message and block, skip check viewID and send prepare message if is in ViewChanging mode
if consensus.mode.Mode() == ViewChanging {
consensus.getLogger().Debug().Msg("[OnAnnounce] Still in ViewChanging Mode, Exiting !!")
utils.Logger().Debug().Msg("[OnAnnounce] Still in ViewChanging Mode, Exiting !!")
return
}
if consensus.checkViewID(recvMsg) != nil {
if consensus.mode.Mode() == Normal {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnAnnounce] ViewID check failed")
@ -259,13 +259,13 @@ func (consensus *Consensus) prepare() {
// TODO: this will not return immediatey, may block
if err := consensus.msgSender.SendWithoutRetry([]p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend)); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnAnnounce] Cannot send prepare message")
utils.Logger().Warn().Err(err).Msg("[OnAnnounce] Cannot send prepare message")
} else {
consensus.getLogger().Info().
utils.Logger().Info().
Str("blockHash", hex.EncodeToString(consensus.blockHash[:])).
Msg("[OnAnnounce] Sent Prepare Message!!")
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Prepare.String()).
Msg("[Announce] Switching Phase")
@ -280,22 +280,22 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
senderKey, err := consensus.verifySenderKey(msg)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnPrepare] VerifySenderKey failed")
utils.Logger().Error().Err(err).Msg("[OnPrepare] VerifySenderKey failed")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnPrepare] Failed to verify sender's signature")
utils.Logger().Error().Err(err).Msg("[OnPrepare] Failed to verify sender's signature")
return
}
recvMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnPrepare] Unparseable validator message")
utils.Logger().Error().Err(err).Msg("[OnPrepare] Unparseable validator message")
return
}
if recvMsg.ViewID != consensus.viewID || recvMsg.BlockNum != consensus.blockNum {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
@ -304,7 +304,7 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
}
if !consensus.PbftLog.HasMatchingViewAnnounce(consensus.blockNum, consensus.viewID, recvMsg.BlockHash) {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
@ -320,7 +320,7 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
consensus.mutex.Lock()
defer consensus.mutex.Unlock()
logger := consensus.getLogger().With().Str("validatorPubKey", validatorPubKey).Logger()
logger := utils.Logger().With().Str("validatorPubKey", validatorPubKey).Logger()
if len(prepareSigs) >= consensus.Quorum() {
// already have enough signatures
logger.Debug().Msg("[OnPrepare] Received Additional Prepare Message")
@ -337,11 +337,11 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
var sign bls.Sign
err = sign.Deserialize(prepareSig)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnPrepare] Failed to deserialize bls signature")
utils.Logger().Error().Err(err).Msg("[OnPrepare] Failed to deserialize bls signature")
return
}
if !sign.VerifyHash(recvMsg.SenderPubkey, consensus.blockHash[:]) {
consensus.getLogger().Error().Msg("[OnPrepare] Received invalid BLS signature")
utils.Logger().Error().Msg("[OnPrepare] Received invalid BLS signature")
return
}
@ -350,7 +350,7 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
prepareSigs[validatorPubKey] = &sign
// Set the bitmap indicating that this validator signed.
if err := prepareBitmap.SetKey(recvMsg.SenderPubkey, true); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnPrepare] prepareBitmap.SetKey failed")
utils.Logger().Warn().Err(err).Msg("[OnPrepare] prepareBitmap.SetKey failed")
return
}
@ -366,7 +366,7 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
_ = protobuf.Unmarshal(msgPayload, msg)
pbftMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnPrepare] Unable to parse pbft message")
utils.Logger().Warn().Err(err).Msg("[OnPrepare] Unable to parse pbft message")
return
}
consensus.PbftLog.AddMessage(pbftMsg)
@ -377,22 +377,22 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
commitPayload := append(blockNumHash, consensus.blockHash[:]...)
consensus.commitSigs[consensus.PubKey.SerializeToHexStr()] = consensus.priKey.SignHash(commitPayload)
if err := consensus.commitBitmap.SetKey(consensus.PubKey, true); err != nil {
consensus.getLogger().Debug().Msg("[OnPrepare] Leader commit bitmap set failed")
utils.Logger().Debug().Msg("[OnPrepare] Leader commit bitmap set failed")
return
}
if err := consensus.msgSender.SendWithRetry(consensus.blockNum, msg_pb.MessageType_PREPARED, []p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend)); err != nil {
consensus.getLogger().Warn().Msg("[OnPrepare] Cannot send prepared message")
utils.Logger().Warn().Msg("[OnPrepare] Cannot send prepared message")
} else {
consensus.getLogger().Debug().
Bytes("blockHash", consensus.blockHash[:]).
utils.Logger().Debug().
Hex("blockHash", consensus.blockHash[:]).
Uint64("blockNum", consensus.blockNum).
Msg("[OnPrepare] Sent Prepared Message!!")
}
consensus.msgSender.StopRetry(msg_pb.MessageType_ANNOUNCE)
consensus.msgSender.StopRetry(msg_pb.MessageType_COMMITTED) // Stop retry committed msg of last consensus
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Commit.String()).
Msg("[OnPrepare] Switching phase")
@ -402,37 +402,37 @@ func (consensus *Consensus) onPrepare(msg *msg_pb.Message) {
}
func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
consensus.getLogger().Debug().Msg("[OnPrepared] Received Prepared message")
utils.Logger().Debug().Msg("[OnPrepared] Received Prepared message")
if consensus.IsLeader() && consensus.mode.Mode() == Normal {
return
}
senderKey, err := consensus.verifySenderKey(msg)
if err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnPrepared] VerifySenderKey failed")
utils.Logger().Debug().Err(err).Msg("[OnPrepared] VerifySenderKey failed")
return
}
if !senderKey.IsEqual(consensus.LeaderPubKey) && consensus.mode.Mode() == Normal && !consensus.ignoreViewIDCheck {
consensus.getLogger().Warn().Msg("[OnPrepared] SenderKey not match leader PubKey")
utils.Logger().Warn().Msg("[OnPrepared] SenderKey not match leader PubKey")
return
}
if err := verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnPrepared] Failed to verify sender's signature")
utils.Logger().Debug().Err(err).Msg("[OnPrepared] Failed to verify sender's signature")
return
}
recvMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnPrepared] Unparseable validator message")
utils.Logger().Debug().Err(err).Msg("[OnPrepared] Unparseable validator message")
return
}
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("MsgViewID", recvMsg.ViewID).
Msg("[OnPrepared] Received prepared message")
if recvMsg.BlockNum < consensus.blockNum {
consensus.getLogger().Debug().Uint64("MsgBlockNum", recvMsg.BlockNum).Msg("Old Block Received, ignoring!!")
utils.Logger().Debug().Uint64("MsgBlockNum", recvMsg.BlockNum).Msg("Old Block Received, ignoring!!")
return
}
@ -440,11 +440,11 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
blockHash := recvMsg.BlockHash
aggSig, mask, err := consensus.ReadSignatureBitmapPayload(recvMsg.Payload, 0)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("ReadSignatureBitmapPayload failed!!")
utils.Logger().Error().Err(err).Msg("ReadSignatureBitmapPayload failed!!")
return
}
if count := utils.CountOneBits(mask.Bitmap); count < consensus.Quorum() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("Need", consensus.Quorum()).
Int("Got", count).
Msg("Not enough signatures in the Prepared msg")
@ -453,7 +453,7 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
if !aggSig.VerifyHash(mask.AggregatePublic, blockHash[:]) {
myBlockHash := common.Hash{}
myBlockHash.SetBytes(consensus.blockHash[:])
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("MsgViewID", recvMsg.ViewID).
Msg("[OnPrepared] failed to verify multi signature for prepare phase")
@ -465,30 +465,30 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
var blockObj types.Block
err = rlp.DecodeBytes(block, &blockObj)
if err != nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Err(err).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnPrepared] Unparseable block header data")
return
}
if blockObj.NumberU64() != recvMsg.BlockNum || recvMsg.BlockNum < consensus.blockNum {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", blockObj.NumberU64()).
Msg("[OnPrepared] BlockNum not match")
return
}
if blockObj.Header().Hash() != recvMsg.BlockHash {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Bytes("MsgBlockHash", recvMsg.BlockHash[:]).
Hex("MsgBlockHash", recvMsg.BlockHash[:]).
Str("blockObjHash", blockObj.Header().Hash().Hex()).
Msg("[OnPrepared] BlockHash not match")
return
}
if consensus.mode.Mode() == Normal {
if err := consensus.VerifyHeader(consensus.ChainReader, blockObj.Header(), true); err != nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Err(err).
Str("inChain", consensus.ChainReader.CurrentHeader().Number.String()).
Str("MsgBlockNum", blockObj.Header().Number.String()).
@ -498,7 +498,7 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
if consensus.BlockVerifier == nil {
// do nothing
} else if err := consensus.BlockVerifier(&blockObj); err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnPrepared] Block verification failed")
utils.Logger().Error().Err(err).Msg("[OnPrepared] Block verification failed")
return
}
}
@ -506,10 +506,10 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
consensus.PbftLog.AddBlock(&blockObj)
recvMsg.Block = []byte{} // save memory space
consensus.PbftLog.AddMessage(recvMsg)
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Bytes("blockHash", recvMsg.BlockHash[:]).
Hex("blockHash", recvMsg.BlockHash[:]).
Msg("[OnPrepared] Prepared message and block added")
consensus.mutex.Lock()
@ -517,13 +517,13 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
consensus.tryCatchup()
if consensus.mode.Mode() == ViewChanging {
consensus.getLogger().Debug().Msg("[OnPrepared] Still in ViewChanging mode, Exiting!!")
utils.Logger().Debug().Msg("[OnPrepared] Still in ViewChanging mode, Exiting!!")
return
}
if consensus.checkViewID(recvMsg) != nil {
if consensus.mode.Mode() == Normal {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnPrepared] ViewID check failed")
@ -531,7 +531,7 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
return
}
if recvMsg.BlockNum > consensus.blockNum {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
Msg("[OnPrepared] Future Block Received, ignoring!!")
@ -565,15 +565,15 @@ func (consensus *Consensus) onPrepared(msg *msg_pb.Message) {
}
if err := consensus.msgSender.SendWithoutRetry([]p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend)); err != nil {
consensus.getLogger().Warn().Msg("[OnPrepared] Cannot send commit message!!")
utils.Logger().Warn().Msg("[OnPrepared] Cannot send commit message!!")
} else {
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("blockNum", consensus.blockNum).
Bytes("blockHash", consensus.blockHash[:]).
Hex("blockHash", consensus.blockHash[:]).
Msg("[OnPrepared] Sent Commit Message!!")
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Commit.String()).
Msg("[OnPrepared] Switching phase")
@ -590,22 +590,22 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
senderKey, err := consensus.verifySenderKey(msg)
if err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnCommit] VerifySenderKey Failed")
utils.Logger().Debug().Err(err).Msg("[OnCommit] VerifySenderKey Failed")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnCommit] Failed to verify sender's signature")
utils.Logger().Debug().Err(err).Msg("[OnCommit] Failed to verify sender's signature")
return
}
recvMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Debug().Err(err).Msg("[OnCommit] Parse pbft message failed")
utils.Logger().Debug().Err(err).Msg("[OnCommit] Parse pbft message failed")
return
}
if recvMsg.ViewID != consensus.viewID || recvMsg.BlockNum != consensus.blockNum {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
@ -615,8 +615,8 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
}
if !consensus.PbftLog.HasMatchingAnnounce(consensus.blockNum, recvMsg.BlockHash) {
consensus.getLogger().Debug().
Bytes("MsgBlockHash", recvMsg.BlockHash[:]).
utils.Logger().Debug().
Hex("MsgBlockHash", recvMsg.BlockHash[:]).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
Msg("[OnCommit] Cannot find matching blockhash")
@ -624,8 +624,8 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
}
if !consensus.PbftLog.HasMatchingPrepared(consensus.blockNum, recvMsg.BlockHash) {
consensus.getLogger().Debug().
Bytes("blockHash", recvMsg.BlockHash[:]).
utils.Logger().Debug().
Hex("blockHash", recvMsg.BlockHash[:]).
Uint64("blockNum", consensus.blockNum).
Msg("[OnCommit] Cannot find matching prepared message")
return
@ -638,7 +638,7 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
consensus.mutex.Lock()
defer consensus.mutex.Unlock()
logger := consensus.getLogger().With().Str("validatorPubKey", validatorPubKey).Logger()
logger := utils.Logger().With().Str("validatorPubKey", validatorPubKey).Logger()
if !consensus.IsValidatorInCommittee(recvMsg.SenderPubkey) {
logger.Error().Msg("[OnCommit] Invalid validator")
return
@ -677,7 +677,7 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
commitSigs[validatorPubKey] = &sign
// Set the bitmap indicating that this validator signed.
if err := commitBitmap.SetKey(recvMsg.SenderPubkey, true); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnCommit] commitBitmap.SetKey failed")
utils.Logger().Warn().Err(err).Msg("[OnCommit] commitBitmap.SetKey failed")
return
}
@ -704,7 +704,7 @@ func (consensus *Consensus) onCommit(msg *msg_pb.Message) {
}
func (consensus *Consensus) finalizeCommits() {
consensus.getLogger().Info().Int("NumCommits", len(consensus.commitSigs)).Msg("[Finalizing] Finalizing Block")
utils.Logger().Info().Int("NumCommits", len(consensus.commitSigs)).Msg("[Finalizing] Finalizing Block")
beforeCatchupNum := consensus.blockNum
beforeCatchupViewID := consensus.viewID
@ -719,7 +719,7 @@ func (consensus *Consensus) finalizeCommits() {
_ = protobuf.Unmarshal(msgPayload, msg)
pbftMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[FinalizeCommits] Unable to parse pbft message")
utils.Logger().Warn().Err(err).Msg("[FinalizeCommits] Unable to parse pbft message")
return
}
consensus.PbftLog.AddMessage(pbftMsg)
@ -728,14 +728,14 @@ func (consensus *Consensus) finalizeCommits() {
// find correct block content
block := consensus.PbftLog.GetBlockByHash(consensus.blockHash)
if block == nil {
consensus.getLogger().Warn().
utils.Logger().Warn().
Str("blockHash", hex.EncodeToString(consensus.blockHash[:])).
Msg("[FinalizeCommits] Cannot find block by hash")
return
}
consensus.tryCatchup()
if consensus.blockNum-beforeCatchupNum != 1 {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("beforeCatchupBlockNum", beforeCatchupNum).
Msg("[FinalizeCommits] Leader cannot provide the correct block for committed message")
return
@ -743,10 +743,10 @@ func (consensus *Consensus) finalizeCommits() {
// if leader success finalize the block, send committed message to validators
if err := consensus.msgSender.SendWithRetry(block.NumberU64(), msg_pb.MessageType_COMMITTED, []p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend)); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[Finalizing] Cannot send committed message")
utils.Logger().Warn().Err(err).Msg("[Finalizing] Cannot send committed message")
} else {
consensus.getLogger().Info().
Bytes("blockHash", consensus.blockHash[:]).
utils.Logger().Info().
Hex("blockHash", consensus.blockHash[:]).
Uint64("blockNum", consensus.blockNum).
Msg("[Finalizing] Sent Committed Message")
}
@ -761,13 +761,13 @@ func (consensus *Consensus) finalizeCommits() {
if consensus.consensusTimeout[timeoutBootstrap].IsActive() {
consensus.consensusTimeout[timeoutBootstrap].Stop()
consensus.getLogger().Debug().Msg("[Finalizing] Start consensus timer; stop bootstrap timer only once")
utils.Logger().Debug().Msg("[Finalizing] Start consensus timer; stop bootstrap timer only once")
} else {
consensus.getLogger().Debug().Msg("[Finalizing] Start consensus timer")
utils.Logger().Debug().Msg("[Finalizing] Start consensus timer")
}
consensus.consensusTimeout[timeoutConsensus].Start()
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("blockNum", beforeCatchupNum).
Uint64("ViewId", beforeCatchupViewID).
Str("blockHash", block.Hash().String()).
@ -779,7 +779,7 @@ func (consensus *Consensus) finalizeCommits() {
}
func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
consensus.getLogger().Debug().Msg("[OnCommitted] Receive committed message")
utils.Logger().Debug().Msg("[OnCommitted] Receive committed message")
if consensus.IsLeader() && consensus.mode.Mode() == Normal {
return
@ -787,26 +787,26 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
senderKey, err := consensus.verifySenderKey(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnCommitted] verifySenderKey failed")
utils.Logger().Warn().Err(err).Msg("[OnCommitted] verifySenderKey failed")
return
}
if !senderKey.IsEqual(consensus.LeaderPubKey) && consensus.mode.Mode() == Normal && !consensus.ignoreViewIDCheck {
consensus.getLogger().Warn().Msg("[OnCommitted] senderKey not match leader PubKey")
utils.Logger().Warn().Msg("[OnCommitted] senderKey not match leader PubKey")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Warn().Err(err).Msg("[OnCommitted] Failed to verify sender's signature")
utils.Logger().Warn().Err(err).Msg("[OnCommitted] Failed to verify sender's signature")
return
}
recvMsg, err := ParsePbftMessage(msg)
if err != nil {
consensus.getLogger().Warn().Msg("[OnCommitted] unable to parse msg")
utils.Logger().Warn().Msg("[OnCommitted] unable to parse msg")
return
}
if recvMsg.BlockNum < consensus.blockNum {
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Uint64("blockNum", consensus.blockNum).
Msg("[OnCommitted] Received Old Blocks!!")
@ -815,13 +815,13 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
aggSig, mask, err := consensus.ReadSignatureBitmapPayload(recvMsg.Payload, 0)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[OnCommitted] readSignatureBitmapPayload failed")
utils.Logger().Error().Err(err).Msg("[OnCommitted] readSignatureBitmapPayload failed")
return
}
// check has 2f+1 signatures
if count := utils.CountOneBits(mask.Bitmap); count < consensus.Quorum() {
consensus.getLogger().Warn().
utils.Logger().Warn().
Int("need", consensus.Quorum()).
Int("got", count).
Msg("[OnCommitted] Not enough signature in committed msg")
@ -832,7 +832,7 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
binary.LittleEndian.PutUint64(blockNumBytes, recvMsg.BlockNum)
commitPayload := append(blockNumBytes, recvMsg.BlockHash[:]...)
if !aggSig.VerifyHash(mask.AggregatePublic, commitPayload) {
consensus.getLogger().Error().
utils.Logger().Error().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnCommitted] Failed to verify the multi signature for commit phase")
return
@ -840,7 +840,7 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
consensus.PbftLog.AddMessage(recvMsg)
consensus.ChainReader.WriteLastCommits(recvMsg.Payload)
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgViewID", recvMsg.ViewID).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[OnCommitted] Committed message added")
@ -852,7 +852,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")
utils.Logger().Debug().Uint64("MsgBlockNum", recvMsg.BlockNum).Msg("[OnCommitted] out of sync")
go func() {
select {
case consensus.blockNumLowChan <- struct{}{}:
@ -867,21 +867,21 @@ func (consensus *Consensus) onCommitted(msg *msg_pb.Message) {
}
// if consensus.checkViewID(recvMsg) != nil {
// consensus.getLogger().Debug("viewID check failed", "viewID", recvMsg.ViewID, "myViewID", consensus.viewID)
// utils.Logger().Debug("viewID check failed", "viewID", recvMsg.ViewID, "myViewID", consensus.viewID)
// return
// }
consensus.tryCatchup()
if consensus.mode.Mode() == ViewChanging {
consensus.getLogger().Debug().Msg("[OnCommitted] Still in ViewChanging mode, Exiting!!")
utils.Logger().Debug().Msg("[OnCommitted] Still in ViewChanging mode, Exiting!!")
return
}
if consensus.consensusTimeout[timeoutBootstrap].IsActive() {
consensus.consensusTimeout[timeoutBootstrap].Stop()
consensus.getLogger().Debug().Msg("[OnCommitted] Start consensus timer; stop bootstrap timer only once")
utils.Logger().Debug().Msg("[OnCommitted] Start consensus timer; stop bootstrap timer only once")
} else {
consensus.getLogger().Debug().Msg("[OnCommitted] Start consensus timer")
utils.Logger().Debug().Msg("[OnCommitted] Start consensus timer")
}
consensus.consensusTimeout[timeoutConsensus].Start()
return
@ -913,7 +913,7 @@ func (consensus *Consensus) LastCommitSig() ([]byte, []byte, error) {
// try to catch up if fall behind
func (consensus *Consensus) tryCatchup() {
consensus.getLogger().Info().Msg("[TryCatchup] commit new blocks")
utils.Logger().Info().Msg("[TryCatchup] commit new blocks")
// if consensus.phase != Commit && consensus.mode.Mode() == Normal {
// return
// }
@ -924,11 +924,11 @@ func (consensus *Consensus) tryCatchup() {
break
}
if len(msgs) > 1 {
consensus.getLogger().Error().
utils.Logger().Error().
Int("numMsgs", len(msgs)).
Msg("[TryCatchup] DANGER!!! we should only get one committed message for a given blockNum")
}
consensus.getLogger().Info().Msg("[TryCatchup] committed message found")
utils.Logger().Info().Msg("[TryCatchup] committed message found")
block := consensus.PbftLog.GetBlockByHash(msgs[0].BlockHash)
if block == nil {
@ -938,36 +938,36 @@ func (consensus *Consensus) tryCatchup() {
if consensus.BlockVerifier == nil {
// do nothing
} else if err := consensus.BlockVerifier(block); err != nil {
consensus.getLogger().Info().Msg("[TryCatchup]block verification faied")
utils.Logger().Info().Msg("[TryCatchup]block verification faied")
return
}
if block.ParentHash() != consensus.ChainReader.CurrentHeader().Hash() {
consensus.getLogger().Debug().Msg("[TryCatchup] parent block hash not match")
utils.Logger().Debug().Msg("[TryCatchup] parent block hash not match")
break
}
consensus.getLogger().Info().Msg("[TryCatchup] block found to commit")
utils.Logger().Info().Msg("[TryCatchup] block found to commit")
preparedMsgs := consensus.PbftLog.GetMessagesByTypeSeqHash(msg_pb.MessageType_PREPARED, msgs[0].BlockNum, msgs[0].BlockHash)
msg := consensus.PbftLog.FindMessageByMaxViewID(preparedMsgs)
if msg == nil {
break
}
consensus.getLogger().Info().Msg("[TryCatchup] prepared message found to commit")
utils.Logger().Info().Msg("[TryCatchup] prepared message found to commit")
consensus.blockHash = [32]byte{}
consensus.blockNum = consensus.blockNum + 1
consensus.viewID = msgs[0].ViewID + 1
consensus.LeaderPubKey = msgs[0].SenderPubkey
consensus.getLogger().Info().Msg("[TryCatchup] Adding block to chain")
utils.Logger().Info().Msg("[TryCatchup] Adding block to chain")
consensus.OnConsensusDone(block)
consensus.ResetState()
select {
case consensus.VerifiedNewBlock <- block:
default:
consensus.getLogger().Info().
utils.Logger().Info().
Str("blockHash", block.Hash().String()).
Msg("[TryCatchup] consensus verified block send to chan failed")
continue
@ -976,7 +976,7 @@ func (consensus *Consensus) tryCatchup() {
break
}
if currentBlockNum < consensus.blockNum {
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("From", currentBlockNum).
Uint64("To", consensus.blockNum).
Msg("[TryCatchup] Caught up!")
@ -996,21 +996,21 @@ func (consensus *Consensus) tryCatchup() {
func (consensus *Consensus) Start(blockChannel chan *types.Block, stopChan chan struct{}, stoppedChan chan struct{}, startChannel chan struct{}) {
go func() {
if consensus.IsLeader() {
consensus.getLogger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Waiting for consensus start")
utils.Logger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Waiting for consensus start")
<-startChannel
// send a signal to indicate it's ready to run consensus
// this signal is consumed by node object to create a new block and in turn trigger a new consensus on it
go func() {
consensus.getLogger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Send ReadySignal")
utils.Logger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Send ReadySignal")
consensus.ReadySignal <- struct{}{}
}()
}
consensus.getLogger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Consensus started")
utils.Logger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Consensus started")
defer close(stoppedChan)
ticker := time.NewTicker(3 * time.Second)
consensus.consensusTimeout[timeoutBootstrap].Start()
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("viewID", consensus.viewID).
Uint64("blockNum", consensus.blockNum).
Msg("[ConsensusMainLoop] Start bootstrap timeout (only once)")
@ -1025,11 +1025,11 @@ func (consensus *Consensus) Start(blockChannel chan *types.Block, stopChan chan
continue
}
if k != timeoutViewChange {
consensus.getLogger().Debug().Msg("[ConsensusMainLoop] Ops Consensus Timeout!!!")
utils.Logger().Debug().Msg("[ConsensusMainLoop] Ops Consensus Timeout!!!")
consensus.startViewChange(consensus.viewID + 1)
break
} else {
consensus.getLogger().Debug().Msg("[ConsensusMainLoop] Ops View Change Timeout!!!")
utils.Logger().Debug().Msg("[ConsensusMainLoop] Ops View Change Timeout!!!")
viewID := consensus.mode.ViewID()
consensus.startViewChange(viewID + 1)
break
@ -1040,24 +1040,24 @@ func (consensus *Consensus) Start(blockChannel chan *types.Block, stopChan chan
consensus.SetViewID(consensus.ChainReader.CurrentHeader().ViewID.Uint64() + 1)
mode := consensus.UpdateConsensusInformation()
consensus.mode.SetMode(mode)
consensus.getLogger().Info().Str("Mode", mode.String()).Msg("Node is in sync")
utils.Logger().Info().Str("Mode", mode.String()).Msg("Node is in sync")
case <-consensus.syncNotReadyChan:
consensus.SetBlockNum(consensus.ChainReader.CurrentHeader().Number.Uint64() + 1)
consensus.mode.SetMode(Syncing)
consensus.getLogger().Info().Msg("Node is out of sync")
utils.Logger().Info().Msg("Node is out of sync")
case newBlock := <-blockChannel:
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("MsgBlockNum", newBlock.NumberU64()).
Msg("[ConsensusMainLoop] Received Proposed New Block!")
if consensus.ShardID == 0 {
// TODO ek/rj - re-enable this after fixing DRand
//if core.IsEpochBlock(newBlock) { // Only beacon chain do randomness generation
// // Receive pRnd from DRG protocol
// consensus.getLogger().Debug("[DRG] Waiting for pRnd")
// utils.Logger().Debug("[DRG] Waiting for pRnd")
// pRndAndBitmap := <-consensus.PRndChannel
// consensus.getLogger().Debug("[DRG] Got pRnd", "pRnd", pRndAndBitmap)
// utils.Logger().Debug("[DRG] Got pRnd", "pRnd", pRndAndBitmap)
// pRnd := [32]byte{}
// copy(pRnd[:], pRndAndBitmap[:32])
// bitmap := pRndAndBitmap[32:]
@ -1072,19 +1072,19 @@ func (consensus *Consensus) Start(blockChannel chan *types.Block, stopChan chan
if err == nil {
// Verify the randomness
_ = blockHash
consensus.getLogger().Info().
Bytes("rnd", rnd[:]).
utils.Logger().Info().
Hex("rnd", rnd[:]).
Msg("[ConsensusMainLoop] Adding randomness into new block")
// newBlock.AddVdf([258]byte{}) // TODO(HB): add real vdf
} else {
//consensus.getLogger().Info("Failed to get randomness", "error", err)
//utils.Logger().Info("Failed to get randomness", "error", err)
}
}
startTime = time.Now()
consensus.msgSender.Reset(newBlock.NumberU64())
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("numTxs", len(newBlock.Transactions())).
Interface("consensus", consensus).
Time("startTime", startTime).

8
consensus/consensus_viewchange_msg.go
Unescape View File

@ -42,8 +42,8 @@ func (consensus *Consensus) constructViewChangeMessage() []byte {
vcMsg.Payload = append(msgToSign[:0:0], msgToSign...)
}
consensus.getLogger().Debug().
Bytes("m1Payload", vcMsg.Payload).
utils.Logger().Debug().
Hex("m1Payload", vcMsg.Payload).
Str("pubKey", consensus.PubKey.SerializeToHexStr()).
Msg("[constructViewChangeMessage]")
@ -89,7 +89,7 @@ func (consensus *Consensus) constructNewViewMessage() []byte {
vcMsg.Payload = consensus.m1Payload
sig2arr := consensus.GetNilSigsArray()
consensus.getLogger().Debug().Int("len", len(sig2arr)).Msg("[constructNewViewMessage] M2 (NIL) type signatures")
utils.Logger().Debug().Int("len", len(sig2arr)).Msg("[constructNewViewMessage] M2 (NIL) type signatures")
if len(sig2arr) > 0 {
m2Sig := bls_cosi.AggregateSig(sig2arr)
vcMsg.M2Aggsigs = m2Sig.Serialize()
@ -97,7 +97,7 @@ func (consensus *Consensus) constructNewViewMessage() []byte {
}
sig3arr := consensus.GetViewIDSigsArray()
consensus.getLogger().Debug().Int("len", len(sig3arr)).Msg("[constructNewViewMessage] M3 (ViewID) type signatures")
utils.Logger().Debug().Int("len", len(sig3arr)).Msg("[constructNewViewMessage] M3 (ViewID) type signatures")
// even we check here for safty, m3 type signatures must >= 2f+1
if len(sig3arr) > 0 {
m3Sig := bls_cosi.AggregateSig(sig3arr)

110
consensus/view_change.go
Unescape View File

@ -123,7 +123,7 @@ func (consensus *Consensus) switchPhase(desirePhase PbftPhase, override bool) {
func (consensus *Consensus) GetNextLeaderKey() *bls.PublicKey {
idx := consensus.getIndexOfPubKey(consensus.LeaderPubKey)
if idx == -1 {
consensus.getLogger().Warn().
utils.Logger().Warn().
Str("key", consensus.LeaderPubKey.SerializeToHexStr()).
Msg("GetNextLeaderKey: currentLeaderKey not found")
}
@ -142,7 +142,7 @@ func (consensus *Consensus) getIndexOfPubKey(pubKey *bls.PublicKey) int {
// ResetViewChangeState reset the state for viewchange
func (consensus *Consensus) ResetViewChangeState() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("Phase", consensus.phase.String()).
Msg("[ResetViewChangeState] Resetting view change state")
consensus.mode.SetMode(Normal)
@ -180,7 +180,7 @@ func (consensus *Consensus) startViewChange(viewID uint64) {
diff := viewID - consensus.viewID
duration := time.Duration(int64(diff) * int64(viewChangeDuration))
consensus.getLogger().Info().
utils.Logger().Info().
Uint64("ViewChangingID", viewID).
Dur("timeoutDuration", duration).
Str("NextLeader", consensus.LeaderPubKey.SerializeToHexStr()).
@ -191,7 +191,7 @@ func (consensus *Consensus) startViewChange(viewID uint64) {
consensus.consensusTimeout[timeoutViewChange].SetDuration(duration)
consensus.consensusTimeout[timeoutViewChange].Start()
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("ViewChangingID", consensus.mode.ViewID()).
Msg("[startViewChange] start view change timer")
}
@ -199,7 +199,7 @@ func (consensus *Consensus) startViewChange(viewID uint64) {
func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
recvMsg, err := ParseViewChangeMessage(msg)
if err != nil {
consensus.getLogger().Warn().Msg("[onViewChange] Unable To Parse Viewchange Message")
utils.Logger().Warn().Msg("[onViewChange] Unable To Parse Viewchange Message")
return
}
newLeaderKey := recvMsg.LeaderPubkey
@ -208,7 +208,7 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
}
if len(consensus.viewIDSigs) >= consensus.Quorum() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("have", len(consensus.viewIDSigs)).
Int("need", consensus.Quorum()).
Str("validatorPubKey", recvMsg.SenderPubkey.SerializeToHexStr()).
@ -218,34 +218,34 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
senderKey, err := consensus.verifyViewChangeSenderKey(msg)
if err != nil {
consensus.getLogger().Debug().Err(err).Msg("[onViewChange] VerifySenderKey Failed")
utils.Logger().Debug().Err(err).Msg("[onViewChange] VerifySenderKey Failed")
return
}
// TODO: if difference is only one, new leader can still propose the same committed block to avoid another view change
if consensus.blockNum > recvMsg.BlockNum {
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[onViewChange] Message BlockNum Is Low")
return
}
if consensus.blockNum < recvMsg.BlockNum {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[onViewChange] New Leader Has Lower Blocknum")
return
}
if consensus.mode.Mode() == ViewChanging && consensus.mode.ViewID() > recvMsg.ViewID {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MyViewChangingID", consensus.mode.ViewID()).
Uint64("MsgViewChangingID", recvMsg.ViewID).
Msg("[onViewChange] ViewChanging ID Is Low")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Debug().Err(err).Msg("[onViewChange] Failed To Verify Sender's Signature")
utils.Logger().Debug().Err(err).Msg("[onViewChange] Failed To Verify Sender's Signature")
return
}
@ -260,11 +260,11 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
preparedMsgs := consensus.PbftLog.GetMessagesByTypeSeq(msg_pb.MessageType_PREPARED, recvMsg.BlockNum)
preparedMsg := consensus.PbftLog.FindMessageByMaxViewID(preparedMsgs)
if preparedMsg == nil {
consensus.getLogger().Debug().Msg("[onViewChange] add my M2(NIL) type messaage")
utils.Logger().Debug().Msg("[onViewChange] add my M2(NIL) type messaage")
consensus.nilSigs[consensus.PubKey.SerializeToHexStr()] = consensus.priKey.SignHash(NIL)
consensus.nilBitmap.SetKey(consensus.PubKey, true)
} else {
consensus.getLogger().Debug().Msg("[onViewChange] add my M1 type messaage")
utils.Logger().Debug().Msg("[onViewChange] add my M1 type messaage")
msgToSign := append(preparedMsg.BlockHash[:], preparedMsg.Payload...)
consensus.bhpSigs[consensus.PubKey.SerializeToHexStr()] = consensus.priKey.SignHash(msgToSign)
consensus.bhpBitmap.SetKey(consensus.PubKey, true)
@ -283,18 +283,18 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
if len(recvMsg.Payload) == 0 {
_, ok := consensus.nilSigs[senderKey.SerializeToHexStr()]
if ok {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Already Received M2 message from validator")
return
}
if !recvMsg.ViewchangeSig.VerifyHash(senderKey, NIL) {
consensus.getLogger().Warn().Msg("[onViewChange] Failed To Verify Signature For M2 Type Viewchange Message")
utils.Logger().Warn().Msg("[onViewChange] Failed To Verify Signature For M2 Type Viewchange Message")
return
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Add M2 (NIL) type message")
consensus.nilSigs[senderKey.SerializeToHexStr()] = recvMsg.ViewchangeSig
@ -302,20 +302,20 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
} else { // m1 type message
_, ok := consensus.bhpSigs[senderKey.SerializeToHexStr()]
if ok {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Already Received M1 Message From the Validator")
return
}
if !recvMsg.ViewchangeSig.VerifyHash(recvMsg.SenderPubkey, recvMsg.Payload) {
consensus.getLogger().Warn().Msg("[onViewChange] Failed to Verify Signature for M1 Type Viewchange Message")
utils.Logger().Warn().Msg("[onViewChange] Failed to Verify Signature for M1 Type Viewchange Message")
return
}
// first time receive m1 type message, need verify validity of prepared message
if len(consensus.m1Payload) == 0 || !bytes.Equal(consensus.m1Payload, recvMsg.Payload) {
if len(recvMsg.Payload) <= 32 {
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("len", len(recvMsg.Payload)).
Msg("[onViewChange] M1 RecvMsg Payload Not Enough Length")
return
@ -323,12 +323,12 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
blockHash := recvMsg.Payload[:32]
aggSig, mask, err := consensus.ReadSignatureBitmapPayload(recvMsg.Payload, 32)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[onViewChange] M1 RecvMsg Payload Read Error")
utils.Logger().Error().Err(err).Msg("[onViewChange] M1 RecvMsg Payload Read Error")
return
}
// check has 2f+1 signature in m1 type message
if count := utils.CountOneBits(mask.Bitmap); count < consensus.Quorum() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("need", consensus.Quorum()).
Int("have", count).
Msg("[onViewChange] M1 Payload Not Have Enough Signature")
@ -337,8 +337,8 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
// Verify the multi-sig for prepare phase
if !aggSig.VerifyHash(mask.AggregatePublic, blockHash[:]) {
consensus.getLogger().Warn().
Bytes("blockHash", blockHash).
utils.Logger().Warn().
Hex("blockHash", blockHash).
Msg("[onViewChange] failed to verify multi signature for m1 prepared payload")
return
}
@ -353,11 +353,11 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
preparedMsg.Payload = make([]byte, len(recvMsg.Payload)-32)
copy(preparedMsg.Payload[:], recvMsg.Payload[32:])
preparedMsg.SenderPubkey = consensus.PubKey
consensus.getLogger().Info().Msg("[onViewChange] New Leader Prepared Message Added")
utils.Logger().Info().Msg("[onViewChange] New Leader Prepared Message Added")
consensus.PbftLog.AddMessage(&preparedMsg)
}
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Add M1 (prepared) type message")
consensus.bhpSigs[senderKey.SerializeToHexStr()] = recvMsg.ViewchangeSig
@ -367,7 +367,7 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
// check and add viewID (m3 type) message signature
_, ok := consensus.viewIDSigs[senderKey.SerializeToHexStr()]
if ok {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Already Received M3(ViewID) message from the validator")
return
@ -375,17 +375,17 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
viewIDHash := make([]byte, 8)
binary.LittleEndian.PutUint64(viewIDHash, recvMsg.ViewID)
if !recvMsg.ViewidSig.VerifyHash(recvMsg.SenderPubkey, viewIDHash) {
consensus.getLogger().Warn().
utils.Logger().Warn().
Uint64("MsgViewID", recvMsg.ViewID).
Msg("[onViewChange] Failed to Verify M3 Message Signature")
return
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("validatorPubKey", senderKey.SerializeToHexStr()).
Msg("[onViewChange] Add M3 (ViewID) type message")
consensus.viewIDSigs[senderKey.SerializeToHexStr()] = recvMsg.ViewidSig
consensus.viewIDBitmap.SetKey(recvMsg.SenderPubkey, true) // Set the bitmap indicating that this validator signed.
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("numSigs", len(consensus.viewIDSigs)).
Int("needed", consensus.Quorum()).
Msg("[onViewChange]")
@ -400,7 +400,7 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
consensus.ReadySignal <- struct{}{}
}()
} else {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Commit.String()).
Msg("[OnViewChange] Switching phase")
@ -408,7 +408,7 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
copy(consensus.blockHash[:], consensus.m1Payload[:32])
aggSig, mask, err := consensus.ReadSignatureBitmapPayload(recvMsg.Payload, 32)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[onViewChange] ReadSignatureBitmapPayload Fail")
utils.Logger().Error().Err(err).Msg("[onViewChange] ReadSignatureBitmapPayload Fail")
return
}
consensus.aggregatedPrepareSig = aggSig
@ -420,7 +420,7 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
commitPayload := append(blockNumBytes, consensus.blockHash[:]...)
consensus.commitSigs[consensus.PubKey.SerializeToHexStr()] = consensus.priKey.SignHash(commitPayload)
if err = consensus.commitBitmap.SetKey(consensus.PubKey, true); err != nil {
consensus.getLogger().Debug().Msg("[OnViewChange] New Leader commit bitmap set failed")
utils.Logger().Debug().Msg("[OnViewChange] New Leader commit bitmap set failed")
return
}
}
@ -428,9 +428,9 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
consensus.mode.SetViewID(recvMsg.ViewID)
msgToSend := consensus.constructNewViewMessage()
consensus.getLogger().Warn().
utils.Logger().Warn().
Int("payloadSize", len(consensus.m1Payload)).
Bytes("M1Payload", consensus.m1Payload).
Hex("M1Payload", consensus.m1Payload).
Msg("[onViewChange] Sent NewView Message")
consensus.msgSender.SendWithRetry(consensus.blockNum, msg_pb.MessageType_NEWVIEW, []p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend))
@ -438,10 +438,10 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
consensus.ResetViewChangeState()
consensus.consensusTimeout[timeoutViewChange].Stop()
consensus.consensusTimeout[timeoutConsensus].Start()
consensus.getLogger().Debug().
utils.Logger().Debug().
Uint64("viewChangingID", consensus.mode.ViewID()).
Msg("[onViewChange] New Leader Start Consensus Timer and Stop View Change Timer")
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("myKey", consensus.PubKey.SerializeToHexStr()).
Uint64("viewID", consensus.viewID).
Uint64("block", consensus.blockNum).
@ -451,27 +451,27 @@ func (consensus *Consensus) onViewChange(msg *msg_pb.Message) {
// TODO: move to consensus_leader.go later
func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
consensus.getLogger().Debug().Msg("[onNewView] Received NewView Message")
utils.Logger().Debug().Msg("[onNewView] Received NewView Message")
senderKey, err := consensus.verifyViewChangeSenderKey(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[onNewView] VerifySenderKey Failed")
utils.Logger().Warn().Err(err).Msg("[onNewView] VerifySenderKey Failed")
return
}
recvMsg, err := consensus.ParseNewViewMessage(msg)
if err != nil {
consensus.getLogger().Warn().Err(err).Msg("[onNewView] Unable to Parse NewView Message")
utils.Logger().Warn().Err(err).Msg("[onNewView] Unable to Parse NewView Message")
return
}
if err = verifyMessageSig(senderKey, msg); err != nil {
consensus.getLogger().Error().Err(err).Msg("[onNewView] Failed to Verify New Leader's Signature")
utils.Logger().Error().Err(err).Msg("[onNewView] Failed to Verify New Leader's Signature")
return
}
consensus.vcLock.Lock()
defer consensus.vcLock.Unlock()
if recvMsg.M3AggSig == nil || recvMsg.M3Bitmap == nil {
consensus.getLogger().Error().Msg("[onNewView] M3AggSig or M3Bitmap is nil")
utils.Logger().Error().Msg("[onNewView] M3AggSig or M3Bitmap is nil")
return
}
m3Sig := recvMsg.M3AggSig
@ -481,7 +481,7 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
binary.LittleEndian.PutUint64(viewIDBytes, recvMsg.ViewID)
// check total number of sigs >= 2f+1
if count := utils.CountOneBits(m3Mask.Bitmap); count < consensus.Quorum() {
consensus.getLogger().Debug().
utils.Logger().Debug().
Int("need", consensus.Quorum()).
Int("have", count).
Msg("[onNewView] Not Have Enough M3 (ViewID) Signature")
@ -489,9 +489,9 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
}
if !m3Sig.VerifyHash(m3Mask.AggregatePublic, viewIDBytes) {
consensus.getLogger().Warn().
utils.Logger().Warn().
Str("m3Sig", m3Sig.SerializeToHexStr()).
Bytes("m3Mask", m3Mask.Bitmap).
Hex("m3Mask", m3Mask.Bitmap).
Uint64("MsgViewID", recvMsg.ViewID).
Msg("[onNewView] Unable to Verify Aggregated Signature of M3 (ViewID) payload")
return
@ -499,10 +499,10 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
m2Mask := recvMsg.M2Bitmap
if recvMsg.M2AggSig != nil {
consensus.getLogger().Debug().Msg("[onNewView] M2AggSig (NIL) is Not Empty")
utils.Logger().Debug().Msg("[onNewView] M2AggSig (NIL) is Not Empty")
m2Sig := recvMsg.M2AggSig
if !m2Sig.VerifyHash(m2Mask.AggregatePublic, NIL) {
consensus.getLogger().Warn().Msg("[onNewView] Unable to Verify Aggregated Signature of M2 (NIL) payload")
utils.Logger().Warn().Msg("[onNewView] Unable to Verify Aggregated Signature of M2 (NIL) payload")
return
}
}
@ -510,18 +510,18 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
// check when M3 sigs > M2 sigs, then M1 (recvMsg.Payload) should not be empty
if m2Mask == nil || m2Mask.Bitmap == nil || (m2Mask != nil && m2Mask.Bitmap != nil && utils.CountOneBits(m3Mask.Bitmap) > utils.CountOneBits(m2Mask.Bitmap)) {
if len(recvMsg.Payload) <= 32 {
consensus.getLogger().Debug().Msg("[onNewView] M1 (prepared) Type Payload Not Have Enough Length")
utils.Logger().Debug().Msg("[onNewView] M1 (prepared) Type Payload Not Have Enough Length")
return
}
// m1 is not empty, check it's valid
blockHash := recvMsg.Payload[:32]
aggSig, mask, err := consensus.ReadSignatureBitmapPayload(recvMsg.Payload, 32)
if err != nil {
consensus.getLogger().Error().Err(err).Msg("[onNewView] ReadSignatureBitmapPayload Failed")
utils.Logger().Error().Err(err).Msg("[onNewView] ReadSignatureBitmapPayload Failed")
return
}
if !aggSig.VerifyHash(mask.AggregatePublic, blockHash) {
consensus.getLogger().Warn().Msg("[onNewView] Failed to Verify Signature for M1 (prepare) message")
utils.Logger().Warn().Msg("[onNewView] Failed to Verify Signature for M1 (prepare) message")
return
}
copy(consensus.blockHash[:], blockHash)
@ -546,7 +546,7 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
// change view and leaderKey to keep in sync with network
if consensus.blockNum != recvMsg.BlockNum {
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("newLeaderKey", consensus.LeaderPubKey.SerializeToHexStr()).
Uint64("MsgBlockNum", recvMsg.BlockNum).
Msg("[onNewView] New Leader Changed")
@ -561,21 +561,21 @@ func (consensus *Consensus) onNewView(msg *msg_pb.Message) {
commitPayload := append(blockNumHash, consensus.blockHash[:]...)
msgToSend := consensus.constructCommitMessage(commitPayload)
consensus.getLogger().Info().Msg("onNewView === commit")
utils.Logger().Info().Msg("onNewView === commit")
consensus.host.SendMessageToGroups([]p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(consensus.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend))
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("From", consensus.phase.String()).
Str("To", Commit.String()).
Msg("[OnViewChange] Switching phase")
consensus.switchPhase(Commit, true)
} else {
consensus.ResetState()
consensus.getLogger().Info().Msg("onNewView === announce")
utils.Logger().Info().Msg("onNewView === announce")
}
consensus.getLogger().Debug().
utils.Logger().Debug().
Str("newLeaderKey", consensus.LeaderPubKey.SerializeToHexStr()).
Msg("new leader changed")
consensus.getLogger().Debug().Msg("validator start consensus timer and stop view change timer")
utils.Logger().Debug().Msg("validator start consensus timer and stop view change timer")
consensus.consensusTimeout[timeoutConsensus].Start()
consensus.consensusTimeout[timeoutViewChange].Stop()
}

2
core/blockchain.go
Unescape View File

@ -266,7 +266,7 @@ func (bc *BlockChain) loadLastState() error {
currentBlock := bc.GetBlockByHash(head)
if currentBlock == nil {
// Corrupt or empty database, init from scratch
utils.Logger().Warn().Bytes("hash", head.Bytes()).Msg("Head block missing, resetting chain")
utils.Logger().Warn().Str("hash", head.Hex()).Msg("Head block missing, resetting chain")
return bc.Reset()
}
// Make sure the state associated with the block is available

2
core/rawdb/accessors_indexes.go
Unescape View File

@ -33,7 +33,7 @@ func ReadTxLookupEntry(db DatabaseReader, hash common.Hash) (common.Hash, uint64
}
var entry TxLookupEntry
if err := rlp.DecodeBytes(data, &entry); err != nil {
utils.Logger().Error().Err(err).Bytes("hash", hash.Bytes()).Msg("Invalid transaction lookup entry RLP")
utils.Logger().Error().Err(err).Hex("hash", hash.Bytes()).Msg("Invalid transaction lookup entry RLP")
return common.Hash{}, 0, 0
}
return entry.BlockHash, entry.BlockIndex, entry.Index

2
core/rawdb/accessors_metadata.go
Unescape View File

@ -52,7 +52,7 @@ func ReadChainConfig(db DatabaseReader, hash common.Hash) *params.ChainConfig {
}
var config params.ChainConfig
if err := json.Unmarshal(data, &config); err != nil {
utils.Logger().Error().Err(err).Bytes("hash", hash.Bytes()).Msg("Invalid chain config JSON")
utils.Logger().Error().Err(err).Hex("hash", hash.Bytes()).Msg("Invalid chain config JSON")
return nil
}
return &config

6
drand/drand_leader.go
Unescape View File

@ -78,7 +78,7 @@ func (dRand *DRand) init(epochBlock *types.Block) {
(*dRand.vrfs)[dRand.SelfAddress] = append(rand[:], proof...)
utils.Logger().Info().
Bytes("msg", msgToSend).
Hex("msg", msgToSend).
Str("leader.PubKey", dRand.leader.ConsensusPubKey.SerializeToHexStr()).
Msg("[DRG] sent init")
dRand.host.SendMessageToGroups([]p2p.GroupID{p2p.NewGroupIDByShardID(p2p.ShardID(dRand.ShardID))}, host.ConstructP2pMessage(byte(17), msgToSend))
@ -167,8 +167,8 @@ func (dRand *DRand) processCommitMessage(message *msg_pb.Message) {
utils.Logger().Error().
Err(err).
Str("validatorAddress", validatorAddress).
Bytes("expectedRand", expectedRand[:]).
Bytes("receivedRand", rand[:]).
Hex("expectedRand", expectedRand[:]).
Hex("receivedRand", rand[:]).
Msg("[DRAND] Failed to verify the VRF")
return
}

4
node/node_handler.go
Unescape View File

@ -478,8 +478,8 @@ func (node *Node) AddNewBlock(newBlock *types.Block) error {
utils.Logger().Error().
Err(err).
Uint64("blockNum", newBlock.NumberU64()).
Bytes("parentHash", newBlock.Header().ParentHash.Bytes()[:]).
Bytes("hash", newBlock.Header().Hash().Bytes()[:]).
Hex("parentHash", newBlock.Header().ParentHash.Bytes()[:]).
Hex("hash", newBlock.Header().Hash().Bytes()[:]).
Msg("Error Adding new block to blockchain")
} else {
utils.Logger().Info().

Write Preview
Loading…
Cancel
Save