search

AztecProtocol / aztec-packages

Apache License 2.0
212 stars 247 forks source link

[archiver] Error "block number mismatch" brings down the node #7918

Closed spalladino closed 3 months ago

spalladino commented 3 months ago

After running a node and prover-node for some time, the following error is hit:

aztec-node-1           | 2024-08-12T15:35:44.773Z aztec:sequencer [INFO] Submitted rollup block 18 with 0 transactions duration=1323.4801650000736ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-node-1           | file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32
aztec-node-1           |             throw new Error('Block number mismatch. Expected: ' + expectedL2BlockNumber + ' but got: ' + blockNum + '.');
aztec-node-1           |                   ^
aztec-node-1           | 
aztec-node-1           | Error: Block number mismatch. Expected: 19 but got: 18.
aztec-node-1           |     at processL2BlockProcessedLogs (file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32:19)
aztec-node-1           |     at retrieveBlockMetadataFromRollup (file:///usr/src/yarn-project/archiver/dest/archiver/data_retrieval.js:25:40)
aztec-node-1           |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-node-1           |     at async Archiver.sync (file:///usr/src/yarn-project/archiver/dest/archiver/archiver.js:134:44)
aztec-node-1           |     at async poll (file:///usr/src/yarn-project/foundation/dest/promise/running-promise.js:22:17)
aztec-node-1           | 
aztec-node-1           | Node.js v18.19.1
aztec-prover-1         | file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32
aztec-prover-1         |             throw new Error('Block number mismatch. Expected: ' + expectedL2BlockNumber + ' but got: ' + blockNum + '.');
aztec-prover-1         |                   ^
aztec-prover-1         | 
aztec-prover-1         | Error: Block number mismatch. Expected: 19 but got: 18.
aztec-prover-1         |     at processL2BlockProcessedLogs (file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32:19)
aztec-prover-1         |     at retrieveBlockMetadataFromRollup (file:///usr/src/yarn-project/archiver/dest/archiver/data_retrieval.js:25:40)
aztec-prover-1         |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-prover-1         |     at async Archiver.sync (file:///usr/src/yarn-project/archiver/dest/archiver/archiver.js:134:44)
aztec-prover-1         |     at async poll (file:///usr/src/yarn-project/foundation/dest/promise/running-promise.js:22:17)
aztec-prover-1         | 
aztec-prover-1         | Node.js v18.19.1

This error is not handled gracefully and kills the node.

spalladino commented 3 months ago

Larger trace:

aztec-node-1           | 2024-08-12T15:34:47.260Z aztec:prover:proving-orchestrator [INFO] Successfully proven block 14!
aztec-node-1           | 2024-08-12T15:34:47.859Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:34:47.927Z aztec:archiver [VERBOSE] Retrieved 1 new L2 blocks between L1 blocks 23 and 23.
aztec-prover-1         | 2024-08-12T15:34:47.934Z aztec:archiver [VERBOSE] Processed 1 new L2 blocks up to 14
aztec-prover-1         | 2024-08-12T15:34:47.936Z aztec:archiver [VERBOSE] Synced to L1 block 23
aztec-node-1           | 2024-08-12T15:34:48.314Z aztec:sequencer:publisher [INFO] Published L2 block to L1 rollup contract gasPrice=1263331993 gasUsed=828429 transactionHash=0x9f824b63ed23e6f488202a270db7b77b912413b8f3c55aaa65c5b8463bab97e4 calldataGas=32728 calldataSize=2692 txCount=1 blockNumber=14 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8 eventName=rollup-published-to-l1 blockHash=0x2688f51df5dd45668decc8cc515cb4c843624dd773219c8c20d000e57513641c
aztec-node-1           | 2024-08-12T15:34:48.315Z aztec:sequencer [INFO] Submitted rollup block 14 with 1 transactions duration=1347.294517999515ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-prover-1         | 2024-08-12T15:34:48.972Z aztec:l2_block_downloader [VERBOSE] Received 1 blocks from archiver after querying from 13 limit 1 (proven false)
aztec-prover-1         | 2024-08-12T15:34:48.972Z aztec:l2_block_downloader [VERBOSE] Reached target block number 13
aztec-prover-1         | 2024-08-12T15:34:48.972Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:34:48.974Z aztec:merkle_trees [VERBOSE] Block 13 is not ours, rolling back world state and committing state from chain
aztec-prover-1         | 2024-08-12T15:34:49.082Z aztec:world_state [VERBOSE] Handled new L2 block eventName=l2-block-handled duration=110.50880299974233 isBlockOurs=false txCount=1 blockNumber=13 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8
aztec-prover-1         | 2024-08-12T15:34:49.082Z aztec:world_state [VERBOSE] Forking world state at 13
aztec-prover-1         | 2024-08-12T15:34:49.163Z aztec:block-proving-job [INFO] Starting block proving job fromBlock=14 toBlock=14
aztec-prover-1         | 2024-08-12T15:34:49.165Z aztec:block-proving-job [VERBOSE] Starting block processing number=14 blockHash=0x2688f51df5dd45668decc8cc515cb4c843624dd773219c8c20d000e57513641c lastArchive=0x033220de7d642003394a80827897b61b8d6194ca3e59a241014a7394cae9dd9e noteHashTreeRoot=0x12bdbeb43c9d77433c2f9a2ee614e0d91f1c25182bdedf3b1853b0245f58af9a nullifierTreeRoot=0x0dae74403cb6b23f21f8ba7df4bf0676a970c2e846a6afcdcd913781ab290a75 publicDataTreeRoot=0x1f6f44032c84e7b4bb2146af06e10083f0ab34cbaab13cdc0ee53e373cdb7a7e historicalHeader=0x2d10b0d9596d1512cafc5dbc68cf9c9de79cc0e284165a403f80c28e5dd22870 chainId=0x0000000000000000000000000000000000000000000000000000000000007a69 version=0x0000000000000000000000000000000000000000000000000000000000000001 blockNumber=0x000000000000000000000000000000000000000000000000000000000000000e slotNumber=0x0000000000000000000000000000000000000000000000000000000000000013 timestamp=0x0000000000000000000000000000000000000000000000000000000066ba2b32 coinbase=0x0000000000000000000000000000000000000000 feeRecipient=0x0000000000000000000000000000000000000000000000000000000000000000 gasFees=[object Object]
aztec-prover-1         | 2024-08-12T15:34:49.165Z aztec:prover:proving-orchestrator [INFO] Starting block 0x000000000000000000000000000000000000000000000000000000000000000e for slot 0x0000000000000000000000000000000000000000000000000000000000000013 with 2 transactions
aztec-prover-1         | 2024-08-12T15:34:49.182Z aztec:prover:proving-orchestrator [INFO] Received transaction: 0d28014d353cec4b31a37bb8675c0f755328965ec1e312e53e97139bca0695af
aztec-prover-1         | 2024-08-12T15:34:49.221Z aztec:block-proving-job [VERBOSE] Processed all txs for block blockNumber=14 blockHash=0x2688f51df5dd45668decc8cc515cb4c843624dd773219c8c20d000e57513641c
aztec-block-watcher-1  | Latest block: 14
aztec-block-watcher-1  | Proven block: 7
aztec-node-1           | 2024-08-12T15:34:56.822Z aztec:node [INFO] Simulating tx 0d23b4dfa0784080006a4a3fbec80c046b7b9c0a7c46d3e3722fec3782967146
aztec-bot-1            | 2024-08-12T15:34:56.858Z aztec:pxe_service [INFO] Executed local simulation for 0d23b4dfa0784080006a4a3fbec80c046b7b9c0a7c46d3e3722fec3782967146
aztec-node-1           | 2024-08-12T15:34:58.372Z aztec:node [INFO] Simulating tx 183b1c0c3c36e7c5eb59bf804ed93a76f9610651fb28f8ff156aa6085275d3da
aztec-bot-1            | 2024-08-12T15:34:58.407Z aztec:pxe_service [INFO] Executed local simulation for 183b1c0c3c36e7c5eb59bf804ed93a76f9610651fb28f8ff156aa6085275d3da
aztec-node-1           | 2024-08-12T15:34:59.878Z aztec:node [INFO] Simulating tx 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e
aztec-bot-1            | 2024-08-12T15:35:00.012Z aztec:pxe_service [INFO] Sending transaction 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e
aztec-node-1           | 2024-08-12T15:35:00.015Z aztec:node [INFO] Received tx 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e
aztec-node-1           | 2024-08-12T15:35:00.015Z aztec:tx_pool [INFO] Adding tx with id 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e eventName=tx-added-to-pool txHash=0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e noteEncryptedLogCount=2 encryptedLogCount=1 unencryptedLogCount=0 noteEncryptedLogSize=1040 encryptedLogSize=524 unencryptedLogSize=8 newCommitmentCount=2 newNullifierCount=2 proofSize=0 size=18041 feePaymentMethod=none classRegisteredCount=0
aztec-bot-1            | 2024-08-12T15:35:00.019Z aztec:bot [INFO] Transaction 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e sent, not waiting for it to be mined
aztec-node-1           | 2024-08-12T15:35:00.573Z aztec:sequencer [INFO] Building block 15 with 1 transactions
aztec-node-1           | 2024-08-12T15:35:00.573Z aztec:prover:proving-orchestrator [INFO] Starting block 0x000000000000000000000000000000000000000000000000000000000000000f for slot 0x0000000000000000000000000000000000000000000000000000000000000014 with 2 transactions
aztec-node-1           | 2024-08-12T15:35:00.576Z aztec:prover:proving-orchestrator [INFO] Received transaction: 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e
aztec-node-1           | 2024-08-12T15:35:01.925Z aztec:prover:proving-orchestrator [INFO] Successfully proven block 15!
aztec-node-1           | 2024-08-12T15:35:02.220Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:35:02.388Z aztec:archiver [VERBOSE] Retrieved 1 new L2 blocks between L1 blocks 24 and 24.
aztec-prover-1         | 2024-08-12T15:35:02.395Z aztec:archiver [VERBOSE] Processed 1 new L2 blocks up to 15
aztec-prover-1         | 2024-08-12T15:35:02.397Z aztec:archiver [VERBOSE] Synced to L1 block 24
aztec-node-1           | 2024-08-12T15:35:02.978Z aztec:sequencer:publisher [INFO] Published L2 block to L1 rollup contract gasPrice=1232233429 gasUsed=828465 transactionHash=0x5989fbb6acda92275c383b26bde2a36b065a8a3cf51a40991a7db3b492878321 calldataGas=32764 calldataSize=2692 txCount=1 blockNumber=15 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8 eventName=rollup-published-to-l1 blockHash=0x300c57790284f84874286f61b575b2d329ef71596d9de2b33a604e54d87d1971
aztec-node-1           | 2024-08-12T15:35:02.979Z aztec:sequencer [INFO] Submitted rollup block 15 with 1 transactions duration=1355.8803909998387ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-prover-1         | 2024-08-12T15:35:04.170Z aztec:l2_block_downloader [VERBOSE] Received 1 blocks from archiver after querying from 14 limit 1 (proven false)
aztec-prover-1         | 2024-08-12T15:35:04.170Z aztec:l2_block_downloader [VERBOSE] Reached target block number 14
aztec-prover-1         | 2024-08-12T15:35:04.170Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:35:04.172Z aztec:merkle_trees [VERBOSE] Block 14 is not ours, rolling back world state and committing state from chain
aztec-prover-1         | 2024-08-12T15:35:04.284Z aztec:world_state [VERBOSE] Handled new L2 block eventName=l2-block-handled duration=113.87341600004584 isBlockOurs=false txCount=1 blockNumber=14 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8
aztec-prover-1         | 2024-08-12T15:35:04.284Z aztec:world_state [VERBOSE] Forking world state at 14
aztec-prover-1         | 2024-08-12T15:35:04.370Z aztec:block-proving-job [INFO] Starting block proving job fromBlock=15 toBlock=15
aztec-prover-1         | 2024-08-12T15:35:04.371Z aztec:block-proving-job [VERBOSE] Starting block processing number=15 blockHash=0x300c57790284f84874286f61b575b2d329ef71596d9de2b33a604e54d87d1971 lastArchive=0x152cce6a71fc7c50d39f1f66276d6a67f652e9865030952c19d18a8b91fbae54 noteHashTreeRoot=0x04afaa77f94da85cdeb49e8c6144c450556728feb94888bb9476ac7253d2906b nullifierTreeRoot=0x2f65b577c42fa36bbb0826b18b8f4f45a671fec90639081c45f7ba419680ab9f publicDataTreeRoot=0x1f6f44032c84e7b4bb2146af06e10083f0ab34cbaab13cdc0ee53e373cdb7a7e historicalHeader=0x2688f51df5dd45668decc8cc515cb4c843624dd773219c8c20d000e57513641c chainId=0x0000000000000000000000000000000000000000000000000000000000007a69 version=0x0000000000000000000000000000000000000000000000000000000000000001 blockNumber=0x000000000000000000000000000000000000000000000000000000000000000f slotNumber=0x0000000000000000000000000000000000000000000000000000000000000014 timestamp=0x0000000000000000000000000000000000000000000000000000000066ba2b3e coinbase=0x0000000000000000000000000000000000000000 feeRecipient=0x0000000000000000000000000000000000000000000000000000000000000000 gasFees=[object Object]
aztec-prover-1         | 2024-08-12T15:35:04.371Z aztec:prover:proving-orchestrator [INFO] Starting block 0x000000000000000000000000000000000000000000000000000000000000000f for slot 0x0000000000000000000000000000000000000000000000000000000000000014 with 2 transactions
aztec-prover-1         | 2024-08-12T15:35:04.390Z aztec:prover:proving-orchestrator [INFO] Received transaction: 0a48ae58904fe4265b789243a80cca7b679a85da3ebfc8e7598aac96e49be80e
aztec-prover-1         | 2024-08-12T15:35:04.442Z aztec:block-proving-job [VERBOSE] Processed all txs for block blockNumber=15 blockHash=0x300c57790284f84874286f61b575b2d329ef71596d9de2b33a604e54d87d1971
aztec-block-watcher-1  | Latest block: 15
aztec-block-watcher-1  | Proven block: 7
aztec-node-1           | 2024-08-12T15:35:11.644Z aztec:node [INFO] Simulating tx 159ea4f19537f6834f0e7abbf04fe3281c57d569ac32da0272e1884f53d7fc0c
aztec-bot-1            | 2024-08-12T15:35:11.891Z aztec:pxe_service [INFO] Executed local simulation for 159ea4f19537f6834f0e7abbf04fe3281c57d569ac32da0272e1884f53d7fc0c
aztec-node-1           | 2024-08-12T15:35:13.398Z aztec:node [INFO] Simulating tx 24d47daaa31ed5a5dd97777b89f51cce86b3f9a7ef297cba54c6059e8d84a347
aztec-bot-1            | 2024-08-12T15:35:13.849Z aztec:pxe_service [INFO] Executed local simulation for 24d47daaa31ed5a5dd97777b89f51cce86b3f9a7ef297cba54c6059e8d84a347
aztec-node-1           | 2024-08-12T15:35:15.334Z aztec:node [INFO] Simulating tx 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39
aztec-bot-1            | 2024-08-12T15:35:15.657Z aztec:pxe_service [INFO] Sending transaction 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39
aztec-node-1           | 2024-08-12T15:35:15.660Z aztec:node [INFO] Received tx 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39
aztec-node-1           | 2024-08-12T15:35:15.661Z aztec:tx_pool [INFO] Adding tx with id 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39 eventName=tx-added-to-pool txHash=25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39 noteEncryptedLogCount=2 encryptedLogCount=1 unencryptedLogCount=0 noteEncryptedLogSize=1040 encryptedLogSize=524 unencryptedLogSize=8 newCommitmentCount=2 newNullifierCount=2 proofSize=0 size=18041 feePaymentMethod=none classRegisteredCount=0
aztec-bot-1            | 2024-08-12T15:35:15.736Z aztec:bot [INFO] Transaction 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39 sent, not waiting for it to be mined
aztec-node-1           | 2024-08-12T15:35:16.141Z aztec:sequencer [INFO] Building block 16 with 1 transactions
aztec-node-1           | 2024-08-12T15:35:16.141Z aztec:prover:proving-orchestrator [INFO] Starting block 0x0000000000000000000000000000000000000000000000000000000000000010 for slot 0x0000000000000000000000000000000000000000000000000000000000000015 with 2 transactions
aztec-node-1           | 2024-08-12T15:35:16.145Z aztec:prover:proving-orchestrator [INFO] Received transaction: 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39
aztec-block-watcher-1  | Latest block: 15
aztec-block-watcher-1  | Proven block: 7
aztec-node-1           | 2024-08-12T15:35:17.489Z aztec:prover:proving-orchestrator [INFO] Successfully proven block 16!
aztec-prover-1         | 2024-08-12T15:35:18.192Z aztec:archiver [VERBOSE] Retrieved 1 new L2 blocks between L1 blocks 25 and 25.
aztec-prover-1         | 2024-08-12T15:35:18.292Z aztec:archiver [VERBOSE] Processed 1 new L2 blocks up to 16
aztec-prover-1         | 2024-08-12T15:35:18.295Z aztec:archiver [VERBOSE] Synced to L1 block 25
aztec-node-1           | 2024-08-12T15:35:18.385Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-node-1           | 2024-08-12T15:35:18.540Z aztec:sequencer:publisher [INFO] Published L2 block to L1 rollup contract gasPrice=1204807561 gasUsed=828441 transactionHash=0x24f3138960efcb6aae0b0ff38b47dff07b1ae21627c0b08b97697c89318f4269 calldataGas=32740 calldataSize=2692 txCount=1 blockNumber=16 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8 eventName=rollup-published-to-l1 blockHash=0x0e068d8d5c0a556fa8dcd769c203ef211c7ed8ccbababbd1b03d22c78049ad43
aztec-node-1           | 2024-08-12T15:35:18.540Z aztec:sequencer [INFO] Submitted rollup block 16 with 1 transactions duration=1350.8911790000275ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-prover-1         | 2024-08-12T15:35:19.375Z aztec:l2_block_downloader [VERBOSE] Received 1 blocks from archiver after querying from 15 limit 1 (proven false)
aztec-prover-1         | 2024-08-12T15:35:19.375Z aztec:l2_block_downloader [VERBOSE] Reached target block number 15
aztec-prover-1         | 2024-08-12T15:35:19.375Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:35:19.377Z aztec:merkle_trees [VERBOSE] Block 15 is not ours, rolling back world state and committing state from chain
aztec-prover-1         | 2024-08-12T15:35:20.927Z aztec:world_state [VERBOSE] Handled new L2 block eventName=l2-block-handled duration=1551.9581779995933 isBlockOurs=false txCount=1 blockNumber=15 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8
aztec-prover-1         | 2024-08-12T15:35:20.927Z aztec:world_state [VERBOSE] Forking world state at 15
aztec-prover-1         | 2024-08-12T15:35:21.347Z aztec:block-proving-job [INFO] Starting block proving job fromBlock=16 toBlock=16
aztec-prover-1         | 2024-08-12T15:35:21.348Z aztec:block-proving-job [VERBOSE] Starting block processing number=16 blockHash=0x0e068d8d5c0a556fa8dcd769c203ef211c7ed8ccbababbd1b03d22c78049ad43 lastArchive=0x300b9dba707e4e35c6549eb593245165e3abe4ceb54b09c4e1b03b04c5cd0a6a noteHashTreeRoot=0x1c42b0b852a6dd162e90cd04d980dc27fff62c69eb6027dd3026728aa9a03d75 nullifierTreeRoot=0x2bf2eaa4ee24cd6baf8477008ee08aecc0077ef8e65b516644a25fac33623e8e publicDataTreeRoot=0x1f6f44032c84e7b4bb2146af06e10083f0ab34cbaab13cdc0ee53e373cdb7a7e historicalHeader=0x300c57790284f84874286f61b575b2d329ef71596d9de2b33a604e54d87d1971 chainId=0x0000000000000000000000000000000000000000000000000000000000007a69 version=0x0000000000000000000000000000000000000000000000000000000000000001 blockNumber=0x0000000000000000000000000000000000000000000000000000000000000010 slotNumber=0x0000000000000000000000000000000000000000000000000000000000000015 timestamp=0x0000000000000000000000000000000000000000000000000000000066ba2b4a coinbase=0x0000000000000000000000000000000000000000 feeRecipient=0x0000000000000000000000000000000000000000000000000000000000000000 gasFees=[object Object]
aztec-prover-1         | 2024-08-12T15:35:21.349Z aztec:prover:proving-orchestrator [INFO] Starting block 0x0000000000000000000000000000000000000000000000000000000000000010 for slot 0x0000000000000000000000000000000000000000000000000000000000000015 with 2 transactions
aztec-prover-1         | 2024-08-12T15:35:21.391Z aztec:prover:proving-orchestrator [INFO] Received transaction: 25820354af9482cce1cc69a877f5ca500c348ae4cae8c8db5b5e5ff7115cff39
aztec-prover-1         | 2024-08-12T15:35:21.449Z aztec:block-proving-job [VERBOSE] Processed all txs for block blockNumber=16 blockHash=0x0e068d8d5c0a556fa8dcd769c203ef211c7ed8ccbababbd1b03d22c78049ad43
aztec-node-1           | 2024-08-12T15:35:27.259Z aztec:node [INFO] Simulating tx 2c78b14922df30ad9975237ef9011d65d8597be622d93a24b9cde207985f0997
aztec-bot-1            | 2024-08-12T15:35:27.297Z aztec:pxe_service [INFO] Executed local simulation for 2c78b14922df30ad9975237ef9011d65d8597be622d93a24b9cde207985f0997
aztec-node-1           | 2024-08-12T15:35:28.816Z aztec:node [INFO] Simulating tx 066890c5cfa255528fb1e1e862e4a6f21329aa4765e0172c36ba1e4fbbb42fc8
aztec-bot-1            | 2024-08-12T15:35:28.855Z aztec:pxe_service [INFO] Executed local simulation for 066890c5cfa255528fb1e1e862e4a6f21329aa4765e0172c36ba1e4fbbb42fc8
aztec-block-watcher-1  | Latest block: 16
aztec-block-watcher-1  | Proven block: 7
aztec-node-1           | 2024-08-12T15:35:30.350Z aztec:node [INFO] Simulating tx 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7
aztec-bot-1            | 2024-08-12T15:35:30.389Z aztec:pxe_service [INFO] Sending transaction 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7
aztec-node-1           | 2024-08-12T15:35:30.392Z aztec:node [INFO] Received tx 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7
aztec-node-1           | 2024-08-12T15:35:30.392Z aztec:tx_pool [INFO] Adding tx with id 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7 eventName=tx-added-to-pool txHash=02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7 noteEncryptedLogCount=2 encryptedLogCount=1 unencryptedLogCount=0 noteEncryptedLogSize=1040 encryptedLogSize=524 unencryptedLogSize=8 newCommitmentCount=2 newNullifierCount=2 proofSize=0 size=18041 feePaymentMethod=none classRegisteredCount=0
aztec-bot-1            | 2024-08-12T15:35:30.397Z aztec:bot [INFO] Transaction 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7 sent, not waiting for it to be mined
aztec-node-1           | 2024-08-12T15:35:30.835Z aztec:sequencer [INFO] Building block 17 with 1 transactions
aztec-node-1           | 2024-08-12T15:35:30.835Z aztec:prover:proving-orchestrator [INFO] Starting block 0x0000000000000000000000000000000000000000000000000000000000000011 for slot 0x0000000000000000000000000000000000000000000000000000000000000016 with 2 transactions
aztec-node-1           | 2024-08-12T15:35:30.839Z aztec:prover:proving-orchestrator [INFO] Received transaction: 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7
aztec-prover-agent-1   | 2024-08-12T15:35:31.050Z aztec:bb-prover [VERBOSE] TubeCircuit (prove) BB out - downloading grumpkin crs...
aztec-node-1           | 2024-08-12T15:35:32.192Z aztec:prover:proving-orchestrator [INFO] Successfully proven block 17!
aztec-node-1           | 2024-08-12T15:35:33.294Z aztec:sequencer:publisher [INFO] Published L2 block to L1 rollup contract gasPrice=1180620541 gasUsed=828453 transactionHash=0xa6e0c5389a5c289a8599163f20c93e730bee947c9d506db175cff760bc680a45 calldataGas=32752 calldataSize=2692 txCount=1 blockNumber=17 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8 eventName=rollup-published-to-l1 blockHash=0x19e80147f4629ce39163380deb15e8d08df72475a5e22b5f8bbb67853e744762
aztec-node-1           | 2024-08-12T15:35:33.294Z aztec:sequencer [INFO] Submitted rollup block 17 with 1 transactions duration=1359.36206900049ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-prover-1         | 2024-08-12T15:35:33.306Z aztec:archiver [VERBOSE] Retrieved 1 new L2 blocks between L1 blocks 26 and 26.
aztec-prover-1         | 2024-08-12T15:35:33.313Z aztec:archiver [VERBOSE] Processed 1 new L2 blocks up to 17
aztec-prover-1         | 2024-08-12T15:35:33.314Z aztec:archiver [VERBOSE] Synced to L1 block 26
aztec-node-1           | 2024-08-12T15:35:33.391Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-agent-1   | 2024-08-12T15:35:34.137Z aztec:bb-prover [VERBOSE] TubeCircuit (prove) BB out - File is empty or there's an error reading it: /usr/src/yarn-project/bb/tmp-6JZvPl/client_ivc_proof
aztec-prover-agent-1   | 2024-08-12T15:35:34.257Z aztec:bb-prover [ERROR] Failed to generate proof for tube proof: Failed to generate proof. Exit code 1. Signal null.
aztec-prover-agent-1   | 2024-08-12T15:35:34.259Z aztec:prover-client:prover-agent [ERROR] Error processing proving job id=7c689027 type=TUBE_PROOF: Error: Failed to generate proof. Exit code 1. Signal null.
aztec-prover-agent-1   |     at BBNativeRollupProver.generateTubeProofWithBB (file:///usr/src/yarn-project/bb-prover/dest/prover/bb_prover.js:276:27)
aztec-prover-agent-1   |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-prover-agent-1   |     at async operation (file:///usr/src/yarn-project/bb-prover/dest/prover/bb_prover.js:317:43)
aztec-prover-agent-1   |     at async runInDirectory (file:///usr/src/yarn-project/foundation/dest/fs/run_in_dir.js:10:16)
aztec-prover-agent-1   |     at async BBNativeRollupProver.getTubeProof (file:///usr/src/yarn-project/bb-prover/dest/prover/bb_prover.js:331:24)
aztec-prover-agent-1   |     at async elapsed (file:///usr/src/yarn-project/foundation/dest/timer/elapsed.js:9:20)
aztec-prover-agent-1   |     at async ProverAgent.work (file:///usr/src/yarn-project/prover-client/dest/prover-agent/prover-agent.js:94:36): Error Failed to generate proof. Exit code 1. Signal null.
aztec-prover-1         | 2024-08-12T15:35:34.261Z aztec:prover-client:prover-pool:queue [WARN] Job id=7c689027 type=TUBE_PROOF failed with error: Failed to generate proof. Exit code 1. Signal null.. Retry 2/3
aztec-prover-agent-1   | 2024-08-12T15:35:34.315Z aztec:bb-prover [INFO] Generated witness circuitName=empty-nested duration=9.291203000582755 inputSize=0 outputSize=0 eventName=circuit-witness-generation
aztec-prover-1         | 2024-08-12T15:35:34.353Z aztec:l2_block_downloader [VERBOSE] Received 1 blocks from archiver after querying from 16 limit 1 (proven false)
aztec-prover-1         | 2024-08-12T15:35:34.353Z aztec:l2_block_downloader [VERBOSE] Reached target block number 16
aztec-prover-1         | 2024-08-12T15:35:34.353Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-prover-1         | 2024-08-12T15:35:34.355Z aztec:merkle_trees [VERBOSE] Block 16 is not ours, rolling back world state and committing state from chain
aztec-prover-1         | 2024-08-12T15:35:34.463Z aztec:world_state [VERBOSE] Handled new L2 block eventName=l2-block-handled duration=109.97028900031 isBlockOurs=false txCount=1 blockNumber=16 noteEncryptedLogLength=1040 noteEncryptedLogCount=2 encryptedLogLength=524 encryptedLogCount=1 unencryptedLogCount=0 unencryptedLogSize=8
aztec-prover-1         | 2024-08-12T15:35:34.463Z aztec:world_state [VERBOSE] Forking world state at 16
aztec-prover-1         | 2024-08-12T15:35:34.557Z aztec:block-proving-job [INFO] Starting block proving job fromBlock=17 toBlock=17
aztec-prover-1         | 2024-08-12T15:35:34.558Z aztec:block-proving-job [VERBOSE] Starting block processing number=17 blockHash=0x19e80147f4629ce39163380deb15e8d08df72475a5e22b5f8bbb67853e744762 lastArchive=0x0c9b2c34cdce462b256b915456f18bb0198c1f5dcb9c354f0bd2e37765939da2 noteHashTreeRoot=0x0619e7b700300ae2b0c08fb86e85d95a116692235f8c970cc35e5ae4aa9b5358 nullifierTreeRoot=0x0a3811c49eebd6686a40a5d95e681b6eb865fa014d7ee9d7213d15d7bee43165 publicDataTreeRoot=0x1f6f44032c84e7b4bb2146af06e10083f0ab34cbaab13cdc0ee53e373cdb7a7e historicalHeader=0x0e068d8d5c0a556fa8dcd769c203ef211c7ed8ccbababbd1b03d22c78049ad43 chainId=0x0000000000000000000000000000000000000000000000000000000000007a69 version=0x0000000000000000000000000000000000000000000000000000000000000001 blockNumber=0x0000000000000000000000000000000000000000000000000000000000000011 slotNumber=0x0000000000000000000000000000000000000000000000000000000000000016 timestamp=0x0000000000000000000000000000000000000000000000000000000066ba2b56 coinbase=0x0000000000000000000000000000000000000000 feeRecipient=0x0000000000000000000000000000000000000000000000000000000000000000 gasFees=[object Object]
aztec-prover-1         | 2024-08-12T15:35:34.559Z aztec:prover:proving-orchestrator [INFO] Starting block 0x0000000000000000000000000000000000000000000000000000000000000011 for slot 0x0000000000000000000000000000000000000000000000000000000000000016 with 2 transactions
aztec-prover-1         | 2024-08-12T15:35:34.576Z aztec:prover:proving-orchestrator [INFO] Received transaction: 02e6061e3a7f196c54924dac70143f8741be419db95c1c1eab78a192676e3cf7
aztec-prover-1         | 2024-08-12T15:35:34.623Z aztec:block-proving-job [VERBOSE] Processed all txs for block blockNumber=17 blockHash=0x19e80147f4629ce39163380deb15e8d08df72475a5e22b5f8bbb67853e744762
aztec-prover-agent-1   | 2024-08-12T15:35:35.634Z aztec:bb-prover [INFO] Generated proof for EmptyNestedArtifact in 1318 ms, size: 409 fields circuitName=empty-nested circuitSize=32 duration=1317.3195989998057 inputSize=0 proofSize=13092 eventName=circuit-proving numPublicInputs=16
aztec-prover-agent-1   | 2024-08-12T15:35:35.635Z aztec:bb-prover [VERBOSE] BB out - Executing BB with: verify_ultra_honk -p /usr/src/yarn-project/bb/tmp-Htw2Xy/proof -k /usr/src/yarn-project/bb/tmp-Htw2Xy/vk
aztec-prover-agent-1   | 2024-08-12T15:35:35.672Z aztec:bb-prover [INFO] Successfully verified proof from key in 36.645440000109375 ms
aztec-prover-agent-1   | 2024-08-12T15:35:35.719Z aztec:bb-prover [INFO] Generated witness circuitName=private-kernel-empty duration=41.82064600009471 inputSize=30777 outputSize=16414 eventName=circuit-witness-generation
aztec-block-watcher-1  | Latest block: 17
aztec-block-watcher-1  | Proven block: 7
aztec-node-1           | 2024-08-12T15:35:42.419Z aztec:sequencer [INFO] Building block 18 with 0 transactions
aztec-node-1           | 2024-08-12T15:35:42.420Z aztec:prover:proving-orchestrator [INFO] Starting block 0x0000000000000000000000000000000000000000000000000000000000000012 for slot 0x0000000000000000000000000000000000000000000000000000000000000017 with 2 transactions
aztec-node-1           | 2024-08-12T15:35:42.506Z aztec:node [INFO] Simulating tx 1e95724451fbde4a0be28d72daacd0d94e88fa19f97c9c83a7db5ff911253f69
aztec-bot-1            | 2024-08-12T15:35:42.556Z aztec:pxe_service [INFO] Executed local simulation for 1e95724451fbde4a0be28d72daacd0d94e88fa19f97c9c83a7db5ff911253f69
aztec-prover-agent-1   | 2024-08-12T15:35:43.560Z aztec:bb-prover [INFO] Generated proof for PrivateKernelEmptyArtifact in 7838 ms, size: 409 fields circuitName=private-kernel-empty circuitSize=1048576 duration=7837.180525000207 inputSize=16414 proofSize=34308 eventName=circuit-proving numPublicInputs=679
aztec-prover-agent-1   | 2024-08-12T15:35:43.562Z aztec:bb-prover [VERBOSE] BB out - Executing BB with: verify_ultra_honk -p /usr/src/yarn-project/bb/tmp-5UmfCg/proof -k /usr/src/yarn-project/bb/tmp-5UmfCg/vk
aztec-prover-agent-1   | 2024-08-12T15:35:43.603Z aztec:bb-prover [INFO] Successfully verified proof from key in 41.055091000162065 ms
aztec-prover-agent-1   | 2024-08-12T15:35:43.604Z aztec:prover-client:prover-agent [VERBOSE] Processed proving job id=7b2dc62a type=PRIVATE_KERNEL_EMPTY duration=9299.110493000597ms
aztec-node-1           | 2024-08-12T15:35:43.740Z aztec:prover:proving-orchestrator [INFO] Successfully proven block 18!
aztec-prover-1         | 2024-08-12T15:35:44.036Z aztec:archiver [VERBOSE] Retrieved 1 new L2 blocks between L1 blocks 27 and 27.
aztec-prover-1         | 2024-08-12T15:35:44.042Z aztec:archiver [VERBOSE] Processed 1 new L2 blocks up to 18
aztec-prover-1         | 2024-08-12T15:35:44.043Z aztec:archiver [VERBOSE] Synced to L1 block 27
aztec-node-1           | 2024-08-12T15:35:44.136Z aztec:kv-store:lmdb [INFO] Opening LMDB database at temporary location
aztec-node-1           | 2024-08-12T15:35:44.480Z aztec:node [INFO] Simulating tx 0e9a0abd985bdef8461f11179286b44f5101239fe328a1b11f5e3e9554ee8adb
aztec-bot-1            | 2024-08-12T15:35:44.515Z aztec:pxe_service [INFO] Executed local simulation for 0e9a0abd985bdef8461f11179286b44f5101239fe328a1b11f5e3e9554ee8adb
aztec-node-1           | 2024-08-12T15:35:44.773Z aztec:sequencer:publisher [INFO] Published L2 block to L1 rollup contract gasPrice=1159289938 gasUsed=632488 transactionHash=0xa598db4494597a361e1e5122f5ab47559db9cf4aec4778dc8812ed072e9fcf3f calldataGas=6668 calldataSize=740 txCount=0 blockNumber=18 noteEncryptedLogLength=0 noteEncryptedLogCount=0 encryptedLogLength=0 encryptedLogCount=0 unencryptedLogCount=0 unencryptedLogSize=0 eventName=rollup-published-to-l1 blockHash=0x2a8fe0a04fdf0ef084d361ee81659e3554b8a67a47ec61bc6dddf14aee8e5c93
aztec-node-1           | 2024-08-12T15:35:44.773Z aztec:sequencer [INFO] Submitted rollup block 18 with 0 transactions duration=1323.4801650000736ms (Submitter: 0x15d34aaf54267db7d7c367839aaf71a00a2c6a65)
aztec-node-1           | file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32
aztec-node-1           |             throw new Error('Block number mismatch. Expected: ' + expectedL2BlockNumber + ' but got: ' + blockNum + '.');
aztec-node-1           |                   ^
aztec-node-1           | 
aztec-node-1           | Error: Block number mismatch. Expected: 19 but got: 18.
aztec-node-1           |     at processL2BlockProcessedLogs (file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32:19)
aztec-node-1           |     at retrieveBlockMetadataFromRollup (file:///usr/src/yarn-project/archiver/dest/archiver/data_retrieval.js:25:40)
aztec-node-1           |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-node-1           |     at async Archiver.sync (file:///usr/src/yarn-project/archiver/dest/archiver/archiver.js:134:44)
aztec-node-1           |     at async poll (file:///usr/src/yarn-project/foundation/dest/promise/running-promise.js:22:17)
aztec-node-1           | 
aztec-node-1           | Node.js v18.19.1
aztec-prover-1         | file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32
aztec-prover-1         |             throw new Error('Block number mismatch. Expected: ' + expectedL2BlockNumber + ' but got: ' + blockNum + '.');
aztec-prover-1         |                   ^
aztec-prover-1         | 
aztec-prover-1         | Error: Block number mismatch. Expected: 19 but got: 18.
aztec-prover-1         |     at processL2BlockProcessedLogs (file:///usr/src/yarn-project/archiver/dest/archiver/eth_log_handlers.js:32:19)
aztec-prover-1         |     at retrieveBlockMetadataFromRollup (file:///usr/src/yarn-project/archiver/dest/archiver/data_retrieval.js:25:40)
aztec-prover-1         |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-prover-1         |     at async Archiver.sync (file:///usr/src/yarn-project/archiver/dest/archiver/archiver.js:134:44)
aztec-prover-1         |     at async poll (file:///usr/src/yarn-project/foundation/dest/promise/running-promise.js:22:17)
aztec-prover-1         | 
aztec-prover-1         | Node.js v18.19.1
aztec-prover-agent-1   | 2024-08-12T15:35:45.337Z aztec:foundation:retry [VERBOSE] JsonRpcClient request provingJobSource_heartbeat to http://aztec-prover failed. Will retry in 1s...
aztec-prover-agent-1   | 2024-08-12T15:35:45.337Z aztec:foundation:retry [ERROR] TypeError: fetch failed
aztec-prover-agent-1   |     at Object.fetch (node:internal/deps/undici/undici:11731:11)
aztec-prover-agent-1   |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
aztec-prover-agent-1   |     at async defaultFetch (file:///usr/src/yarn-project/foundation/dest/json-rpc/client/json_rpc_client.js:29:16)
aztec-prover-agent-1   |     at async retry (file:///usr/src/yarn-project/foundation/dest/retry/index.js:47:20)
aztec-prover-agent-1   |     at async file:///usr/src/yarn-project/foundation/dest/json-rpc/client/json_rpc_client.js:64:16
aztec-prover-agent-1   |     at async request (file:///usr/src/yarn-project/foundation/dest/json-rpc/client/json_rpc_client.js:88:21)
aztec-prover-agent-1   |     at async RunningPromise.fn (file:///usr/src/yarn-project/prover-client/dest/prover-agent/prover-agent.js:43:17)
aztec-prover-agent-1   |     at async poll (file:///usr/src/yarn-project/foundation/dest/promise/running-promise.js:22:17) {
aztec-prover-agent-1   |   cause: [Error]
aztec-prover-agent-1   | }
spalladino commented 3 months ago

Note that the block published that broke things had zero txs in it