Additional logging on a block proposing.

consensus/consensus.go

@@ -31,6 +31,16 @@ const (
 
 var errLeaderPriKeyNotFound = errors.New("leader private key not found locally")
 
+type Proposal struct {
+	Type   ProposalType
+	Caller string
+}
+
+// NewProposal creates a new proposal
+func NewProposal(t ProposalType) Proposal {
+	return Proposal{Type: t, Caller: utils.GetCallStackInfo(2)}
+}
+
 // ProposalType is to indicate the type of signal for new block proposal
 type ProposalType byte
 
@@ -90,7 +100,7 @@ type Consensus struct {
 	// ViewChange struct
 	vc *viewChange
 	// Signal channel for proposing a new block and start new consensus
-	readySignal chan ProposalType
+	readySignal chan Proposal
 	// Channel to send full commit signatures to finish new block proposal
 	commitSigChannel chan []byte
 	// The post-consensus job func passed from Node object
@@ -151,11 +161,11 @@ func (consensus *Consensus) ChainReader() engine.ChainReader {
 	return consensus.Blockchain()
 }
 
-func (consensus *Consensus) ReadySignal(p ProposalType) {
+func (consensus *Consensus) ReadySignal(p Proposal) {
 	consensus.readySignal <- p
 }
 
-func (consensus *Consensus) GetReadySignal() chan ProposalType {
+func (consensus *Consensus) GetReadySignal() chan Proposal {
 	return consensus.readySignal
 }
 
@@ -304,7 +314,7 @@ func New(
 	// displayed on explorer as Height right now
 	consensus.setCurBlockViewID(0)
 	consensus.SlashChan = make(chan slash.Record)
-	consensus.readySignal = make(chan ProposalType)
+	consensus.readySignal = make(chan Proposal)
 	consensus.commitSigChannel = make(chan []byte)
 	// channel for receiving newly generated VDF
 	consensus.RndChannel = make(chan [vdfAndSeedSize]byte)

consensus/consensus_service.go

@@ -459,7 +459,7 @@ func (consensus *Consensus) updateConsensusInformation() Mode {
 					consensus.GetLogger().Info().
 						Str("myKey", myPubKeys.SerializeToHexStr()).
 						Msg("[UpdateConsensusInformation] I am the New Leader")
-					consensus.ReadySignal(SyncProposal)
+					consensus.ReadySignal(NewProposal(SyncProposal))
 				}()
 			}
 			return Normal

consensus/consensus_v2.go

@@ -258,7 +258,7 @@ func (consensus *Consensus) finalCommit() {
 			// No pipelining
 			go func() {
 				consensus.getLogger().Info().Msg("[finalCommit] sending block proposal signal")
-				consensus.ReadySignal(SyncProposal)
+				consensus.ReadySignal(NewProposal(SyncProposal))
 			}()
 		} else {
 			// pipelining
@@ -334,7 +334,7 @@ func (consensus *Consensus) StartChannel() {
 		consensus.start = true
 		consensus.getLogger().Info().Time("time", time.Now()).Msg("[ConsensusMainLoop] Send ReadySignal")
 		consensus.mutex.Unlock()
-		consensus.ReadySignal(SyncProposal)
+		consensus.ReadySignal(NewProposal(SyncProposal))
 		return
 	}
 	consensus.mutex.Unlock()
@@ -586,7 +586,7 @@ func (consensus *Consensus) preCommitAndPropose(blk *types.Block) error {
 		// Send signal to Node to propose the new block for consensus
 		consensus.getLogger().Info().Msg("[preCommitAndPropose] sending block proposal signal")
 		consensus.mutex.Unlock()
-		consensus.ReadySignal(AsyncProposal)
+		consensus.ReadySignal(NewProposal(AsyncProposal))
 	}()
 
 	return nil
@@ -814,7 +814,7 @@ func (consensus *Consensus) setupForNewConsensus(blk *types.Block, committedMsg
 				blockPeriod := consensus.BlockPeriod
 				go func() {
 					<-time.After(blockPeriod)
-					consensus.ReadySignal(SyncProposal)
+					consensus.ReadySignal(NewProposal(SyncProposal))
 				}()
 			}
 		}

consensus/view_change.go

@@ -429,7 +429,7 @@ func (consensus *Consensus) onViewChange(recvMsg *FBFTMessage) {
 				consensus.getLogger().Error().Err(err).Msg("[onViewChange] startNewView failed")
 				return
 			}
-			go consensus.ReadySignal(SyncProposal)
+			go consensus.ReadySignal(NewProposal(SyncProposal))
 			return
 		}
 

internal/utils/utils.go

@@ -92,9 +92,9 @@ func GetCallStackInfo(depthList ...int) string {
 	} else {
 		depth = depthList[0]
 	}
-	function, file, line, _ := runtime.Caller(depth)
-	return fmt.Sprintf("File: %s  Function: %s Line: %d",
-		chopPath(file), runtime.FuncForPC(function).Name(), line,
+	_, file, line, _ := runtime.Caller(depth)
+	return fmt.Sprintf("%s:%d",
+		file, line,
 	)
 }
 

node/node_newblock.go

@@ -48,20 +48,21 @@ func (node *Node) WaitForConsensusReadyV2(cs *consensus.Consensus, stopChan chan
 				utils.Logger().Warn().
 					Msg("Consensus new block proposal: STOPPED!")
 				return
-			case proposalType := <-cs.GetReadySignal():
+			case proposal := <-cs.GetReadySignal():
 				for retryCount := 0; retryCount < 3 && cs.IsLeader(); retryCount++ {
 					time.Sleep(SleepPeriod)
 					utils.Logger().Info().
 						Uint64("blockNum", cs.Blockchain().CurrentBlock().NumberU64()+1).
-						Bool("asyncProposal", proposalType == consensus.AsyncProposal).
+						Bool("asyncProposal", proposal.Type == consensus.AsyncProposal).
+						Str("called", proposal.Caller).
 						Msg("PROPOSING NEW BLOCK ------------------------------------------------")
 
 					// Prepare last commit signatures
 					newCommitSigsChan := make(chan []byte)
 
 					go func() {
 						waitTime := 0 * time.Second
-						if proposalType == consensus.AsyncProposal {
+						if proposal.Type == consensus.AsyncProposal {
 							waitTime = consensus.CommitSigReceiverTimeout
 						}
 						select {