diff --git a/common/common.go b/common/common.go index 11eb9976291..97f7c03c308 100644 --- a/common/common.go +++ b/common/common.go @@ -284,6 +284,17 @@ func GetHeaderTimestamps( return timestampSec, timestampMs, nil } +// LogPrettifiedHeader logs the prettified representation of the provided header or an error if prettification fails +func LogPrettifiedHeader(header data.HeaderHandler, sentOrReceived string, version string) { + headerOutput, err := PrettifyStruct(header) + message := fmt.Sprintf("Proposed header %s %s", sentOrReceived, version) + if err != nil { + log.Debug(message, "error", err) + } else { + log.Debug(message, "header", headerOutput) + } +} + // PrettifyStruct returns a JSON string representation of a struct, converting byte slices to hex // and formatting big number values into readable strings. Useful for logging or debugging. func PrettifyStruct(x interface{}) (string, error) { diff --git a/common/common_test.go b/common/common_test.go index 289d8fb1868..b3b8d32a496 100644 --- a/common/common_test.go +++ b/common/common_test.go @@ -482,6 +482,34 @@ func TestPrettifyStruct(t *testing.T) { t.Log("MetaBlock", prettified) }) + + t.Run("with headers V3", func(t *testing.T) { + t.Parallel() + + header := &block.HeaderV3{} + prettified, err := common.PrettifyStruct(header) + require.NoError(t, err) + t.Log("HeaderV3", prettified) + + meta := &block.MetaBlockV3{} + prettified, err = common.PrettifyStruct(meta) + require.NoError(t, err) + t.Log("MetaBlockV3", prettified) + }) + + t.Run("with complete headers V3", func(t *testing.T) { + t.Parallel() + + header := createMockShardHeaderV3() + prettified, err := common.PrettifyStruct(header) + require.NoError(t, err) + t.Log("HeaderV3", prettified) + + meta := createMockMetaHeaderV3() + prettified, err = common.PrettifyStruct(meta) + require.NoError(t, err) + t.Log("MetaBlockV3", prettified) + }) } func TestGetLastBaseExecutionResultHandler(t *testing.T) { @@ -666,6 +694,184 @@ func TestPrepareLogEventsKey(t *testing.T) { require.Equal(t, "logsLogsX", string(logs)) } +func createMockMetaHeaderV3() *block.MetaBlockV3 { + return &block.MetaBlockV3{ + Nonce: 42, + Epoch: 2, + Round: 15, + TimestampMs: 123456789, + PrevHash: []byte("prev_hash"), + PrevRandSeed: []byte("prev_seed"), + RandSeed: []byte("new_seed"), + ChainID: []byte("chain-id"), + SoftwareVersion: []byte("v1.0.0"), + LeaderSignature: []byte("leader_signature"), + + MiniBlockHeaders: []block.MiniBlockHeader{ + {Hash: []byte("meta-to-s0"), SenderShardID: core.MetachainShardId, ReceiverShardID: 0}, + {Hash: []byte("meta-to-s1"), SenderShardID: core.MetachainShardId, ReceiverShardID: 1}, + }, + + ShardInfo: []block.ShardData{ + { + ShardID: 0, + Round: 10, + Nonce: 41, + Epoch: 1, + HeaderHash: []byte("shard0-hash"), + ShardMiniBlockHeaders: []block.MiniBlockHeader{ + {SenderShardID: 0, ReceiverShardID: 1, Hash: []byte("s0-to-s1")}, + }, + }, + { + ShardID: 1, + Round: 11, + Nonce: 40, + Epoch: 1, + HeaderHash: []byte("shard1-hash"), + ShardMiniBlockHeaders: []block.MiniBlockHeader{ + {SenderShardID: 1, ReceiverShardID: 0, Hash: []byte("s1-to-s0")}, + }, + }, + }, + ShardInfoProposal: []block.ShardDataProposal{ + {ShardID: 0, HeaderHash: []byte("shard-0-hash"), Nonce: 41, Round: 10, Epoch: 1}, + {ShardID: 1, HeaderHash: []byte("shard-1-hash"), Nonce: 40, Round: 11, Epoch: 1}, + }, + ExecutionResults: []*block.MetaExecutionResult{ + { + ExecutionResult: &block.BaseMetaExecutionResult{ + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("hdr-hash-10"), + HeaderNonce: 39, + HeaderRound: 10, + HeaderEpoch: 1, + RootHash: []byte("root-hash-10"), + }, + AccumulatedFeesInEpoch: big.NewInt(1000), + DevFeesInEpoch: big.NewInt(100), + ValidatorStatsRootHash: []byte("validator-stats-root-hash"), + }, + AccumulatedFees: big.NewInt(1000), + DeveloperFees: big.NewInt(100), + ReceiptsHash: []byte("receipts hash"), + }, + { + ExecutionResult: &block.BaseMetaExecutionResult{ + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("hdr-hash-11"), + HeaderNonce: 40, + HeaderRound: 11, + HeaderEpoch: 1, + RootHash: []byte("root-hash-11"), + }, + AccumulatedFeesInEpoch: big.NewInt(2000), + DevFeesInEpoch: big.NewInt(200), + ValidatorStatsRootHash: []byte("validator-stats-root-hash-1"), + }, + AccumulatedFees: big.NewInt(2000), + DeveloperFees: big.NewInt(200), + ReceiptsHash: []byte("receipts-hash-1"), + }, + { + ExecutionResult: &block.BaseMetaExecutionResult{ + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("hdr-hash-last"), + HeaderNonce: 41, + HeaderRound: 12, + HeaderEpoch: 2, + RootHash: []byte("root-hash-last"), + }, + AccumulatedFeesInEpoch: big.NewInt(3000), + DevFeesInEpoch: big.NewInt(300), + ValidatorStatsRootHash: []byte("validator-stats-root-hash-2"), + }, + AccumulatedFees: big.NewInt(3000), + DeveloperFees: big.NewInt(300), + ReceiptsHash: []byte("receipts-hash-2"), + }, + }, + + LastExecutionResult: &block.MetaExecutionResultInfo{ + NotarizedInRound: 14, + ExecutionResult: &block.BaseMetaExecutionResult{ + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("hdr-hash-last"), + HeaderNonce: 41, + HeaderRound: 12, + HeaderEpoch: 2, + RootHash: []byte("root-hash-last"), + }, + AccumulatedFeesInEpoch: big.NewInt(3000), + DevFeesInEpoch: big.NewInt(300), + ValidatorStatsRootHash: []byte("validator-stats-root-hash-2"), + }, + }, + } +} + +func createMockShardHeaderV3() *block.HeaderV3 { + var hdrNonce = uint64(56) + var hdrRound = uint64(67) + var hdrEpoch = uint32(78) + return &block.HeaderV3{ + Nonce: hdrNonce, + PrevHash: []byte("prev hash"), + PrevRandSeed: []byte("prev rand seed"), + RandSeed: []byte("rand seed"), + ShardID: uint32(1), + TimestampMs: 0, + Round: hdrRound, + Epoch: hdrEpoch, + BlockBodyType: block.TxBlock, + LeaderSignature: []byte("signature"), + MiniBlockHeaders: nil, + PeerChanges: nil, + MetaBlockHashes: nil, + TxCount: 0, + ChainID: []byte("chain ID"), + SoftwareVersion: []byte("version"), + LastExecutionResult: &block.ExecutionResultInfo{ + ExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("header hash"), + HeaderNonce: hdrNonce - 1, + HeaderRound: hdrRound - 1, + HeaderEpoch: hdrEpoch, + RootHash: []byte("root hash"), + }, + NotarizedInRound: hdrRound - 1, + }, + ExecutionResults: []*block.ExecutionResult{ + { + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("header hash"), + HeaderNonce: hdrNonce - 3, + HeaderRound: hdrRound - 3, + HeaderEpoch: hdrEpoch - 1, + RootHash: []byte("root hash"), + }, + }, + { + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("header hash"), + HeaderNonce: hdrNonce - 2, + HeaderRound: hdrRound - 2, + HeaderEpoch: hdrEpoch - 1, + RootHash: []byte("root hash"), + }, + }, + { + BaseExecutionResult: &block.BaseExecutionResult{ + HeaderHash: []byte("header hash"), + HeaderNonce: hdrNonce - 1, + HeaderRound: hdrRound - 1, + HeaderEpoch: hdrEpoch, + RootHash: []byte("root hash"), + }, + }, + }, + } +} func TestGetMiniBlockHeadersFromExecResult(t *testing.T) { t.Parallel() diff --git a/consensus/spos/bls/v1/subroundBlock.go b/consensus/spos/bls/v1/subroundBlock.go index aa485392962..860081042ba 100644 --- a/consensus/spos/bls/v1/subroundBlock.go +++ b/consensus/spos/bls/v1/subroundBlock.go @@ -230,6 +230,8 @@ func (sr *subroundBlock) sendHeaderAndBlockBody( sr.SetBody(bodyHandler) sr.SetHeader(headerHandler) + // log the header output for debugging purposes + common.LogPrettifiedHeader(headerHandler, "sent", "v1") return true } @@ -449,6 +451,9 @@ func (sr *subroundBlock) receivedBlockBodyAndHeader(ctx context.Context, cnsDta spos.LeaderPeerHonestyIncreaseFactor, ) + // log the header output for debugging purposes + common.LogPrettifiedHeader(sr.GetHeader(), "received", "v1") + return blockProcessedWithSuccess } diff --git a/consensus/spos/bls/v1/subroundEndRound.go b/consensus/spos/bls/v1/subroundEndRound.go index e622c8ccd68..700e193fb0b 100644 --- a/consensus/spos/bls/v1/subroundEndRound.go +++ b/consensus/spos/bls/v1/subroundEndRound.go @@ -392,6 +392,9 @@ func (sr *subroundEndRound) doEndRoundJobByLeader() bool { log.Debug("step 3: Body and Header have been committed and header has been broadcast") + // log the header output for debugging purposes + common.LogPrettifiedHeader(sr.GetHeader(), "committed", "v1") + err = sr.broadcastBlockDataLeader() if err != nil { log.Debug("doEndRoundJobByLeader.broadcastBlockDataLeader", "error", err.Error()) @@ -708,6 +711,9 @@ func (sr *subroundEndRound) doEndRoundJobByParticipant(cnsDta *consensus.Message log.Debug("step 3: Body and Header have been committed") + // log the header output for debugging purposes + common.LogPrettifiedHeader(header, "committed", "v1") + headerTypeMsg := "received" if cnsDta != nil { headerTypeMsg = "assembled" diff --git a/consensus/spos/bls/v2/subroundBlock.go b/consensus/spos/bls/v2/subroundBlock.go index 6336b07af55..c0547c79d44 100644 --- a/consensus/spos/bls/v2/subroundBlock.go +++ b/consensus/spos/bls/v2/subroundBlock.go @@ -337,11 +337,7 @@ func (sr *subroundBlock) sendBlockHeader( sr.SetHeader(headerHandler) // log the header output for debugging purposes - headerOutput, err := common.PrettifyStruct(headerHandler) - if err == nil { - log.Debug("proposed header sent", "header", headerOutput) - } - + common.LogPrettifiedHeader(headerHandler, "sent", "v2") return true } @@ -654,10 +650,7 @@ func (sr *subroundBlock) receivedBlockHeader(headerHandler data.HeaderHandler) { ) // log the header output for debugging purposes - headerOutput, err := common.PrettifyStruct(headerHandler) - if err == nil { - log.Debug("proposed header received", "header", headerOutput) - } + common.LogPrettifiedHeader(sr.GetHeader(), "received", "v2") } func (sr *subroundBlock) checkSupernovaHeader(headerHandler data.HeaderHandler) bool { diff --git a/consensus/spos/bls/v2/subroundEndRound.go b/consensus/spos/bls/v2/subroundEndRound.go index 9967fe44651..b62d28fef6a 100644 --- a/consensus/spos/bls/v2/subroundEndRound.go +++ b/consensus/spos/bls/v2/subroundEndRound.go @@ -353,6 +353,9 @@ func (sr *subroundEndRound) finalizeConfirmedBlock() bool { msg := fmt.Sprintf("Added proposed block with nonce %d in blockchain", sr.GetHeader().GetNonce()) log.Debug(display.Headline(msg, sr.SyncTimer().FormattedCurrentTime(), "+")) + // log the header output for debugging purposes + common.LogPrettifiedHeader(sr.GetHeader(), "committed", "v2") + sr.updateMetricsForLeader() return true diff --git a/node/chainSimulator/process/processor.go b/node/chainSimulator/process/processor.go index 9612c4cc22e..6cb8db4d096 100644 --- a/node/chainSimulator/process/processor.go +++ b/node/chainSimulator/process/processor.go @@ -214,10 +214,7 @@ func (creator *blocksCreator) CreateNewBlock() (*dtos.BroadcastData, error) { return nil, err } - headerOutput, err := common.PrettifyStruct(header) - if err == nil { - log.Debug("Proposed header sent", "header", headerOutput) - } + common.LogPrettifiedHeader(header, "sent", "v3") err = creator.nodeHandler.GetProcessComponents().BlockProcessor().VerifyBlockProposal(header, block, func() time.Duration { return time.Second