Skip to content
This repository was archived by the owner on Feb 17, 2025. It is now read-only.

Add l2block log dump when storing error. Refactor ProcessBatchV2 logs #3129

Merged
ToniRamirezM merged 4 commits into from
Jan 24, 2024
Merged

Add l2block log dump when storing error. Refactor ProcessBatchV2 logs #3129

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
6d07dc6
add l2block log dump when storing error. refactor ProcessBatchV2 logs
agnusmor Jan 23, 2024
c54d265
add AddL2Block log
agnusmor Jan 23, 2024
087b7d3
fix index AddL2Block log
agnusmor Jan 23, 2024
7441d8b
use aux variable to avoid reusing poiner
ToniRamirezM Jan 24, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 24 additions & 1 deletion sequencer/l2block.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -138,6 +138,8 @@ func (f *finalizer) storePendingL2Blocks(ctx context.Context) {
err := f.storeL2Block(ctx, l2Block)

if err != nil {
// Dump L2Block info
f.logL2Block(l2Block)
f.Halt(ctx, fmt.Errorf("error storing L2 block %d [%d], error: %v", l2Block.batchResponse.BlockResponses[0].BlockNumber, l2Block.trackingNum, err))
}

Expand Down Expand Up @@ -444,8 +446,8 @@ func (f *finalizer) openNewWIPL2Block(ctx context.Context, prevTimestamp time.Ti
newL2Block := &L2Block{}

// Tracking number
newL2Block.trackingNum = f.l2BlockCounter
f.l2BlockCounter++
newL2Block.trackingNum = f.l2BlockCounter

log.Debugf("opening new WIP L2 block [%d]", newL2Block.trackingNum)

Expand Down Expand Up @@ -553,3 +555,24 @@ func (f *finalizer) executeNewWIPL2Block(ctx context.Context) (*state.ProcessBat

return batchResponse, nil
}

func (f *finalizer) logL2Block(l2Block *L2Block) {
var blockResp *state.ProcessBlockResponse
if l2Block.batchResponse != nil {
if len(l2Block.batchResponse.BlockResponses) > 0 {
blockResp = l2Block.batchResponse.BlockResponses[0]
}
}

if blockResp != nil {
log.Infof("DUMP L2 block %d [%d], Timestamp: %d, ParentHash: %s, Coinbase: %s, GER: %s, BlockHashL1: %s, GasUsed: %d, BlockInfoRoot: %s, BlockHash: %s",
blockResp.BlockNumber, l2Block.trackingNum, blockResp.Timestamp, blockResp.ParentHash, blockResp.Coinbase, blockResp.GlobalExitRoot, blockResp.BlockHashL1,
blockResp.GasUsed, blockResp.BlockInfoRoot, blockResp.BlockHash)

for i, txResp := range blockResp.TransactionResponses {
log.Infof(" tx[%d] Hash: %s, HashL2: %s, StateRoot: %s, Type: %d, GasLeft: %d, GasUsed: %d, GasRefund: %d, CreateAddress: %s, ChangesStateRoot: %v, EGP: %s, EGPPct: %d, HasGaspriceOpcode: %v, HasBalanceOpcode: %v",
i, txResp.TxHash, txResp.TxHashL2_V2, txResp.StateRoot, txResp.Type, txResp.GasLeft, txResp.GasUsed, txResp.GasRefunded, txResp.CreateAddress, txResp.ChangesStateRoot, txResp.EffectiveGasPrice,
txResp.EffectivePercentage, txResp.HasGaspriceOpcode, txResp.HasBalanceOpcode)
}
}
}
121 changes: 55 additions & 66 deletions state/batchV2.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -262,7 +262,7 @@ func (s *State) sendBatchRequestToExecutorV2(ctx context.Context, batchRequest *
return nil, ErrExecutorNil
}

request := "BatchNum: %v, OldBatchNum: %v, From: %v, OldStateRoot: %v, L1InfoRoot: %v, OldAccInputHash: %v, TimestampLimit: %v, Coinbase: %v, UpdateMerkleTree: %v, SkipFirstChangeL2Block: %v, SkipWriteBlockInfoRoot: %v, ChainId: %v, ForkId: %v, ContextId: %v, SkipVerifyL1InfoRoot: %v, ForcedBlockhashL1: %v, L1InfoTreeData: %+v, BatchL2Data: %v"
batchRequestLog := "BatchNum: %v, OldBatchNum: %v, From: %v, OldStateRoot: %v, L1InfoRoot: %v, OldAccInputHash: %v, TimestampLimit: %v, Coinbase: %v, UpdateMerkleTree: %v, SkipFirstChangeL2Block: %v, SkipWriteBlockInfoRoot: %v, ChainId: %v, ForkId: %v, ContextId: %v, SkipVerifyL1InfoRoot: %v, ForcedBlockhashL1: %v, L1InfoTreeData: %+v, BatchL2Data: %v"

l1DataStr := ""
for i, l1Data := range batchRequest.L1InfoTreeData {
Expand All @@ -272,91 +272,80 @@ func (s *State) sendBatchRequestToExecutorV2(ctx context.Context, batchRequest *
l1DataStr = l1DataStr[:len(l1DataStr)-1]
}

request = fmt.Sprintf(request, batchRequest.OldBatchNum+1, batchRequest.OldBatchNum, batchRequest.From, hex.EncodeToHex(batchRequest.OldStateRoot), hex.EncodeToHex(batchRequest.L1InfoRoot),
batchRequestLog = fmt.Sprintf(batchRequestLog, batchRequest.OldBatchNum+1, batchRequest.OldBatchNum, batchRequest.From, hex.EncodeToHex(batchRequest.OldStateRoot), hex.EncodeToHex(batchRequest.L1InfoRoot),
hex.EncodeToHex(batchRequest.OldAccInputHash), batchRequest.TimestampLimit, batchRequest.Coinbase, batchRequest.UpdateMerkleTree, batchRequest.SkipFirstChangeL2Block,
batchRequest.SkipWriteBlockInfoRoot, batchRequest.ChainId, batchRequest.ForkId, batchRequest.ContextId, batchRequest.SkipVerifyL1InfoRoot, hex.EncodeToHex(batchRequest.ForcedBlockhashL1),
l1DataStr, hex.EncodeToHex(batchRequest.BatchL2Data))

log.Debugf("executor batch request: %s", request)
log.Debugf("executor batchRequest: %s", batchRequestLog)

now := time.Now()
res, err := s.executorClient.ProcessBatchV2(ctx, batchRequest)
batchResponse, err := s.executorClient.ProcessBatchV2(ctx, batchRequest)
if err != nil {
log.Errorf("Error s.executorClient.ProcessBatchV2: %v", err)
log.Errorf("Error s.executorClient.ProcessBatchV2: %s", err.Error())
log.Errorf("Error s.executorClient.ProcessBatchV2 response: %v", res)
} else if res.Error != executor.ExecutorError_EXECUTOR_ERROR_NO_ERROR {
log.Debug(processBatchResponseToString(res, ""))
err = executor.ExecutorErr(res.Error)
s.eventLog.LogExecutorErrorV2(ctx, res.Error, batchRequest)
} else if res.ErrorRom != executor.RomError_ROM_ERROR_NO_ERROR && executor.IsROMOutOfCountersError(res.ErrorRom) {
log.Warn("OOC error: ", processBatchResponseToString(res, ""))
} else if res.ErrorRom != executor.RomError_ROM_ERROR_NO_ERROR {
log.Warn(processBatchResponseToString(res, ""))
err = executor.RomErr(res.ErrorRom)
log.Errorf("error executor ProcessBatchV2: %v", err)
log.Errorf("error executor ProcessBatchV2: %s", err.Error())
log.Errorf("error executor ProcessBatchV2 response: %v", batchResponse)
} else {
batchResponseToString := processBatchResponseToString(batchResponse)
if batchResponse.Error != executor.ExecutorError_EXECUTOR_ERROR_NO_ERROR {
err = executor.ExecutorErr(batchResponse.Error)
log.Debug("executor batchRequest, executor error: %v", err)
log.Debug(batchResponseToString)
s.eventLog.LogExecutorErrorV2(ctx, batchResponse.Error, batchRequest)
} else if batchResponse.ErrorRom != executor.RomError_ROM_ERROR_NO_ERROR && executor.IsROMOutOfCountersError(batchResponse.ErrorRom) {
log.Warn("executor batchRequest, ROM OOC, error: %v", err)
log.Warn(batchResponseToString)
} else if batchResponse.ErrorRom != executor.RomError_ROM_ERROR_NO_ERROR {
err = executor.RomErr(batchResponse.ErrorRom)
log.Warn("executor batchRequest, ROM error: %v", err)
log.Warn(batchResponseToString)
} else {
log.Debug(batchResponseToString)
}
}

//workarroundDuplicatedBlock(res)
elapsed := time.Since(now)
if caller != metrics.DiscardCallerLabel {
metrics.ExecutorProcessingTime(string(caller), elapsed)
}

log.Infof("batch %d took %v to be processed by the executor ", batchRequest.OldBatchNum+1, elapsed)

return res, err
return batchResponse, err
}

func processBatchResponseToString(r *executor.ProcessBatchResponseV2, prefix string) string {
res := prefix + "ProcessBatchResponseV2: \n"
res += prefix + fmt.Sprintf("NewStateRoot: %v\n", hex.EncodeToHex(r.NewStateRoot))
res += prefix + fmt.Sprintf("NewAccInputHash: %v\n", hex.EncodeToHex(r.NewAccInputHash))
res += prefix + fmt.Sprintf("NewLocalExitRoot: %v\n", hex.EncodeToHex(r.NewLocalExitRoot))
res += prefix + fmt.Sprintf("NewBatchNumber: %v\n", r.NewBatchNum)
res += prefix + fmt.Sprintf("Error: %v\n", r.Error)
res += prefix + fmt.Sprintf("FlushId: %v\n", r.FlushId)
res += prefix + fmt.Sprintf("StoredFlushId: %v\n", r.StoredFlushId)
res += prefix + fmt.Sprintf("ProverId: %v\n", r.ProverId)
res += prefix + fmt.Sprintf("GasUsed: %v\n", r.GasUsed)
res += prefix + fmt.Sprintf("ForkId: %v\n", r.ForkId)
for blockIndex, block := range r.BlockResponses {
newPrefix := prefix + " " + fmt.Sprintf("BlockResponse[%v]: ", blockIndex)
res += blockResponseToString(block, newPrefix)
}
return res
func processBatchResponseToString(batchResponse *executor.ProcessBatchResponseV2) string {
batchResponseLog := "executor batchResponse: NewStateRoot: %v, NewAccInputHash: %v, NewLocalExitRoot: %v, NewBatchNumber: %v, GasUsed: %v, FlushId: %v, StoredFlushId: %v, ProverId:%v, ForkId:%v, Error: %v\n"
batchResponseLog = fmt.Sprintf(batchResponseLog, hex.EncodeToHex(batchResponse.NewStateRoot), hex.EncodeToHex(batchResponse.NewAccInputHash), hex.EncodeToHex(batchResponse.NewLocalExitRoot),
batchResponse.NewBatchNum, batchResponse.GasUsed, batchResponse.FlushId, batchResponse.StoredFlushId, batchResponse.ProverId, batchResponse.ForkId, batchResponse.Error)

for blockIndex, block := range batchResponse.BlockResponses {
prefix := " " + fmt.Sprintf("block[%v]: ", blockIndex)
batchResponseLog += blockResponseToString(block, prefix)
}

return batchResponseLog
}
func blockResponseToString(r *executor.ProcessBlockResponseV2, prefix string) string {
res := prefix + "ProcessBlockResponseV2:----------------------------- \n"
res += prefix + fmt.Sprintf("ParentHash: %v\n", common.BytesToHash(r.ParentHash))
res += prefix + fmt.Sprintf("Coinbase: %v\n", r.Coinbase)
res += prefix + fmt.Sprintf("GasLimit: %v\n", r.GasLimit)
res += prefix + fmt.Sprintf("BlockNumber: %v\n", r.BlockNumber)
res += prefix + fmt.Sprintf("Timestamp: %v\n", r.Timestamp)
res += prefix + fmt.Sprintf("GlobalExitRoot:%v\n", common.BytesToHash(r.Ger))
res += prefix + fmt.Sprintf("BlockHashL1: %v\n", common.BytesToHash(r.BlockHashL1))
res += prefix + fmt.Sprintf("GasUsed: %v\n", r.GasUsed)
res += prefix + fmt.Sprintf("BlockInfoRoot: %v\n", common.BytesToHash(r.BlockInfoRoot))
res += prefix + fmt.Sprintf("BlockHash: %v\n", common.BytesToHash(r.BlockHash))
for txIndex, tx := range r.Responses {
newPrefix := prefix + " " + fmt.Sprintf("TransactionResponse[%v]: ", txIndex)
res += transactionResponseToString(tx, newPrefix)
}
res += prefix + "----------------------------------------------------------------- [Block]\n"

return res
func blockResponseToString(blockResponse *executor.ProcessBlockResponseV2, prefix string) string {
blockResponseLog := prefix + "ParentHash: %v, Coinbase: %v, GasLimit: %v, BlockNumber: %v, Timestamp: %v, GlobalExitRoot: %v, BlockHashL1: %v, GasUsed: %v, BlockInfoRoot: %v, BlockHash: %v\n"
blockResponseLog = fmt.Sprintf(blockResponseLog, common.BytesToHash(blockResponse.ParentHash), blockResponse.Coinbase, blockResponse.GasLimit, blockResponse.BlockNumber, blockResponse.Timestamp,
common.BytesToHash(blockResponse.Ger), common.BytesToHash(blockResponse.BlockHashL1), blockResponse.GasUsed, common.BytesToHash(blockResponse.BlockInfoRoot), common.BytesToHash(blockResponse.BlockHash))

for txIndex, tx := range blockResponse.Responses {
prefix := " " + fmt.Sprintf("tx[%v]: ", txIndex)
blockResponseLog += transactionResponseToString(tx, prefix)
}

return blockResponseLog
}

func transactionResponseToString(r *executor.ProcessTransactionResponseV2, prefix string) string {
res := prefix + "ProcessTransactionResponseV2:----------------------------------- \n"
res += prefix + fmt.Sprintf("TxHash: %v\n", common.BytesToHash(r.TxHash))
res += prefix + fmt.Sprintf("TxHashL2: %v\n", common.BytesToHash(r.TxHashL2))
res += prefix + fmt.Sprintf("Type: %v\n", r.Type)
res += prefix + fmt.Sprintf("Error: %v\n", r.Error)
res += prefix + fmt.Sprintf("GasUsed: %v\n", r.GasUsed)
res += prefix + fmt.Sprintf("GasLeft: %v\n", r.GasLeft)
res += prefix + fmt.Sprintf("GasRefund:%v\n", r.GasRefunded)
res += prefix + fmt.Sprintf("StateRoot:%v\n", common.BytesToHash(r.StateRoot))
res += prefix + "----------------------------------------------------------------- [Transaction]\n"

return res
func transactionResponseToString(txResponse *executor.ProcessTransactionResponseV2, prefix string) string {
txResponseLog := prefix + "TxHash: %v, TxHashL2: %v, Type: %v, StateRoot:%v, GasUsed: %v, GasLeft: %v, GasRefund: %v, Error: %v\n"
txResponseLog = fmt.Sprintf(txResponseLog, common.BytesToHash(txResponse.TxHash), common.BytesToHash(txResponse.TxHashL2), txResponse.Type,
common.BytesToHash(txResponse.StateRoot), txResponse.GasUsed, txResponse.GasLeft, txResponse.GasRefunded, txResponse.Error)

return txResponseLog
}

// ProcessAndStoreClosedBatchV2 is used by the Synchronizer to add a closed batch into the data base. Values returned are the new stateRoot,
Expand Down
12 changes: 0 additions & 12 deletions state/convertersV2.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -168,18 +168,6 @@ func (s *State) convertToProcessTransactionResponseV2(responses []*executor.Proc

if tx != nil {
result.Tx = *tx
log.Debugf("ProcessTransactionResponseV2[TxHash]: %v", result.TxHash)
if response.Error == executor.RomError_ROM_ERROR_NO_ERROR {
log.Debugf("ProcessTransactionResponseV2[Nonce]: %v", result.Tx.Nonce())
}
log.Debugf("ProcessTransactionResponseV2[StateRoot]: %v", result.StateRoot.String())
log.Debugf("ProcessTransactionResponseV2[Error]: %v", result.RomError)
log.Debugf("ProcessTransactionResponseV2[GasUsed]: %v", result.GasUsed)
log.Debugf("ProcessTransactionResponseV2[GasLeft]: %v", result.GasLeft)
log.Debugf("ProcessTransactionResponseV2[GasRefunded]: %v", result.GasRefunded)
log.Debugf("ProcessTransactionResponseV2[ChangesStateRoot]: %v", result.ChangesStateRoot)
log.Debugf("ProcessTransactionResponseV2[EffectiveGasPrice]: %v", result.EffectiveGasPrice)
log.Debugf("ProcessTransactionResponseV2[EffectivePercentage]: %v", result.EffectivePercentage)
}

results = append(results, result)
Expand Down
5 changes: 4 additions & 1 deletion state/pgstatestorage/l2block.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -206,11 +206,14 @@ func (p *PostgresStorage) AddL2Block(ctx context.Context, batchNumber uint64, l2
return err
}

l2TxHash, err := state.GetL2Hash(*tx)
aux := *tx
l2TxHash, err := state.GetL2Hash(aux)
if err != nil {
return err
}

log.Debugf("[AddL2Block] L2Block num: %d, tx[%d] = txHash: %s, txHashL2: %s", l2Block.Number().Uint64(), idx, tx.Hash().String(), l2TxHash.String())

txRow := []interface{}{tx.Hash().String(), encoded, decoded, l2Block.Number().Uint64(), txsEGPData[idx].EffectivePercentage, egpLogBytes, l2TxHash.String()}
txRows = append(txRows, txRow)
}
Expand Down