status-im / nimbus-eth2

Nim implementation of the Ethereum Beacon Chain
https://nimbus.guide
Other
517 stars 222 forks source link

Display of block reward difference between EL block and MEV block #6465

Open mrzigha opened 1 month ago

mrzigha commented 1 month ago

Is your feature request related to a problem? Please describe. Other CL clients such as Teku and Lighthouse log the difference between the execution payload supplied by the EL client and that supplied by the MEV relay.

Describe the solution you'd like Display the builder's block rewards (in wei) when a block is proposed (MEV), as well as the rewards of the block provided by the client execution (in wei).

Describe alternatives you've considered Integrate this functionality into the RPC.

tersec commented 1 month ago

This already exists as Compared engine and builder block bids logging: https://github.com/status-im/nimbus-eth2/blob/7d00786d5ed2024f309b7f4d638272d212ea94dc/beacon_chain/validators/beacon_validators.nim#L1204-L1235

mrzigha commented 1 month ago

@tersec I don' see anything like that in logs. I've proposed the slot 9640969. This is my Nimbus logs :

INF 2024-08-01 12:34:11.000+00:00 Slot start topics="beacnde" head=7251a54a:9640968 delay=132us863ns finalized=301278:83710527 peers=19 slot=9640969 sync=synced epoch=301280

INF 2024-08-01 12:34:12.796+00:00 Proposing blinded Builder API block topics="beacval" blindedBlock="(blck: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\", eth1data: (deposit_root: 53dfea7fd938e6d95d991f8a47d31b9546b1258975d1d58538f0da130e55cffd, deposit_count: 1623969, block_hash: 93594fa2248c8edc6471f24bf46b669afde0d215f1d526b873630311d82e2ebc), graffiti: \"Nimbus/v24.7.0-99f657-stateofus\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 68, deposits_len: 0, voluntary_exits_len: 0, sync_committee_participants: 499, block_number: 20433725, block_hash: \"0xb92eee1fcf44b02cab4bf6aeead4f1c14d51a94b81650c4c8f7b6117ad8191d9\", parent_hash: \"0x7e27e81f49a7dbd30aa808482d08c0831b067770602ed03c32effc2339077692\", fee_recipient: \"0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97\", bls_to_execution_changes_len: 0, blob_kzg_commitments_len: 0), signature: \"8062f55a\")"

NTC 2024-08-01 12:34:14.334+00:00 Block not sent topics="beacval" blockRoot=611ad743 blck="(slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\", eth1data: (deposit_root: 53dfea7fd938e6d95d991f8a47d31b9546b1258975d1d58538f0da130e55cffd, deposit_count: 1623969, block_hash: 93594fa2248c8edc6471f24bf46b669afde0d215f1d526b873630311d82e2ebc), graffiti: \"Nimbus/v24.7.0-99f657-stateofus\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 68, deposits_len: 0, voluntary_exits_len: 0, sync_committee_participants: 499, block_number: 20433725, block_hash: \"0xb92eee1fcf44b02cab4bf6aeead4f1c14d51a94b81650c4c8f7b6117ad8191d9\", parent_hash: \"0x7e27e81f49a7dbd30aa808482d08c0831b067770602ed03c32effc2339077692\", fee_recipient: \"0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97\", bls_to_execution_changes_len: 0, blob_kzg_commitments_len: 5)" signature=8062f55a error="No peers on libp2p topic"

NTC 2024-08-01 12:34:14.337+00:00 Blob sent topics="beacval" blob="(index: 0, blob: \"0x380001fbfc0054217416f86140140fe9e0886cfa5dd700000001fbe4019be4af\", bloblen: 131072, block_header: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\"), kzg_commitment: \"0x809980fdafdd21ad8cb885082d95284a413b5724d2487d7b62116f43bdc0aa6577cd15157c79db51ef841fe417f3044b\", kzg_proof: \"0x8c2d0c36986f8e525c2b25e5bb99819574f9a0dbbec24fed2bafd07b32d7e7362cb76b066b1eafe99d05ade6f09761b0\")"

NTC 2024-08-01 12:34:14.337+00:00 Blob sent topics="beacval" blob="(index: 1, blob: \"0x2d0001fbfc0054217416f86140140fe9e0886cfa5dd700010001fbe4b4980c22\", bloblen: 131072, block_header: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\"), kzg_commitment: \"0x918bd47f6461f5dcc4b3d3eb435dcc630bfa8d74577bbf512dc2050c951b6a3598f9aee32e3e5017023f6b74291eb09e\", kzg_proof: \"0xa5a6a87180af06942f2742bde93a44d0970cad4314e57121ef3af64fd416b7b25e9ae2b388b2ce7b41549c776ef6bacf\")"

NTC 2024-08-01 12:34:14.337+00:00 Blob sent topics="beacval" blob="(index: 2, blob: \"0x280001fbfc0054217416f86140140fe9e0886cfa5dd700020001fbe48ce8db19\", bloblen: 131072, block_header: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\"), kzg_commitment: \"0xb110fee59d38648bca8ce7d3cfb0c3ca875fa20d560c1212b3bf9cf06296ccb7582bde059585e7a73f205dbfef0a34ad\", kzg_proof: \"0xa726242836f659047ba5b2c25add0e025423e6b72f050454999c3af936d9ffa3a690244b58d6de6b56994d3e4e30955a\")"

NTC 2024-08-01 12:34:14.338+00:00 Blob sent topics="beacval" blob="(index: 3, blob: \"0x350001fbfc0054217416f86140140fe9e0886cfa5dd700030001fbe4ebd6816b\", bloblen: 131072, block_header: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\"), kzg_commitment: \"0xa9e9b0be268867412077d1d42a80ff9d393dbb5949fc4d2e5344df81cdeb94cf9e70583d6e00abbe5d578bdb2bec8a85\", kzg_proof: \"0xb4d3da5fbc2b8c1c65a7a88e2a4a220f77c501066ec4444c0f80dca623fd3b00ad58d79816d475467496fb15c711dfe0\")"

NTC 2024-08-01 12:34:14.338+00:00 Blob sent topics="beacval" blob="(index: 4, blob: \"0x1a0001ebca0054217416f86140140fe9e0886cfa5dd700040001ebb234e84840\", bloblen: 131072, block_header: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\"), kzg_commitment: \"0xaa6493ea1443ab0e26e90b7085078b6cb847d628de61c308823ff1ee63b302cd7f12a6b29421ae1464ee7c5531087355\", kzg_proof: \"0xb6a81045c6d42fc472fdff4c5c4dbb5ef1c7f50b54f2b8909229b9280695a6aef8f33223876588bc7b48bd01df4c4fa6\")"

NTC 2024-08-01 12:34:14.342+00:00 Block proposed (MEV)                       topics="beacval" blockRoot=611ad743 blck="(blck: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\", eth1data: (deposit_root: 53dfea7fd938e6d95d991f8a47d31b9546b1258975d1d58538f0da130e55cffd, deposit_count: 1623969, block_hash: 93594fa2248c8edc6471f24bf46b669afde0d215f1d526b873630311d82e2ebc), graffiti: \"Nimbus/v24.7.0-99f657-stateofus\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 68, deposits_len: 0, voluntary_exits_len: 0, sync_committee_participants: 499, block_number: 20433725, block_hash: \"0xb92eee1fcf44b02cab4bf6aeead4f1c14d51a94b81650c4c8f7b6117ad8191d9\", parent_hash: \"0x7e27e81f49a7dbd30aa808482d08c0831b067770602ed03c32effc2339077692\", fee_recipient: \"0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97\", bls_to_execution_changes_len: 0, blob_kzg_commitments_len: 5), signature: \"8062f55a\")" signature=8062f55a

INF 2024-08-01 12:34:21.117+00:00 Slot end topics="beacnde" slot=9640969 nextActionWait=1s882ms593us900ns nextAttestationSlot=9640970 nextProposalSlot=-1 syncCommitteeDuties=none head=611ad743:9640969

INF 2024-08-01 12:34:23.000+00:00 Slot start                                 topics="beacnde" head=611ad743:9640969 delay=188us295ns finalized=301278:83710527 peers=23 slot=9640970 sync=synced epoch=301280

INF 2024-08-01 12:45:10.551+00:00 Block proposal included                    topics="chaindag" slot=9640969 validator=b8915bde
docker logs nimbus  2>&1 | grep -i "Compared"

Doesn't print anything.

tersec commented 1 month ago

Regarding

NTC 2024-08-01 12:34:14.334+00:00 Block not sent topics="beacval" blockRoot=611ad743 blck="(slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\", eth1data: (deposit_root: 53dfea7fd938e6d95d991f8a47d31b9546b1258975d1d58538f0da130e55cffd, deposit_count: 1623969, block_hash: 93594fa2248c8edc6471f24bf46b669afde0d215f1d526b873630311d82e2ebc), graffiti: \"Nimbus/v24.7.0-99f657-stateofus\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 68, deposits_len: 0, voluntary_exits_len: 0, sync_committee_participants: 499, block_number: 20433725, block_hash: \"0xb92eee1fcf44b02cab4bf6aeead4f1c14d51a94b81650c4c8f7b6117ad8191d9\", parent_hash: \"0x7e27e81f49a7dbd30aa808482d08c0831b067770602ed03c32effc2339077692\", fee_recipient: \"0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97\", bls_to_execution_changes_len: 0, blob_kzg_commitments_len: 5)" signature=8062f55a error="No peers on libp2p topic"

that's cosmetic.

More generally, your logs also don't show Requesting engine payload: https://github.com/status-im/nimbus-eth2/blob/99f657e548162767e354b3be00c336116d69a97b/beacon_chain/validators/beacon_validators.nim#L439-L443

so it's not clear if there even was an engine payload to compare with. Do you have a functioning EL it's communicating with and can you check the logs from it for whether it sent a getPayload on/just before that block?

Alternatively, oddly it also does not display Did not receive expected engine bid: https://github.com/status-im/nimbus-eth2/blob/99f657e548162767e354b3be00c336116d69a97b/beacon_chain/validators/beacon_validators.nim#L1225-L1233

Finally, I'd note that

INF 2024-08-01 12:34:11.000+00:00 Slot start topics="beacnde" head=7251a54a:9640968 delay=132us863ns finalized=301278:83710527 peers=19 slot=9640969 sync=synced epoch=301280

INF 2024-08-01 12:34:12.796+00:00 Proposing blinded Builder API block topics="beacval" blindedBlock="(blck: (slot: 9640969, proposer_index: 1246017, parent_root: \"7251a54a\", state_root: \"6d462606\", eth1data: (deposit_root: 53dfea7fd938e6d95d991f8a47d31b9546b1258975d1d58538f0da130e55cffd, deposit_count: 1623969, block_hash: 93594fa2248c8edc6471f24bf46b669afde0d215f1d526b873630311d82e2ebc), graffiti: \"Nimbus/v24.7.0-99f657-stateofus\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 68, deposits_len: 0, voluntary_exits_len: 0, sync_committee_participants: 499, block_number: 20433725, block_hash: \"0xb92eee1fcf44b02cab4bf6aeead4f1c14d51a94b81650c4c8f7b6117ad8191d9\", parent_hash: \"0x7e27e81f49a7dbd30aa808482d08c0831b067770602ed03c32effc2339077692\", fee_recipient: \"0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97\", bls_to_execution_changes_len: 0, blob_kzg_commitments_len: 0), signature: \"8062f55a\")"

it's almost 2 seconds until it sends out the block. Is this deliberate, or do you have mev-boost logs showing what's happening here? Because in theory the getHeader/submitBlindedBlock from the builder API should be (significantly) faster.

The overall point here is that the lack of the comparison is the least weird thing about these logs. It's apparently a downstream symptom of a deeper root cause.

mrzigha commented 1 month ago

@tersec

My EL logs:

01 Aug 12:34:07 | Produced block 20433725 (0x5e31a4...ab59fc), diff: 0, tx count: 81 
01 Aug 12:34:07 | Improved post-merge block 20433725 (0x5e31a4...ab59fc), diff: 0, tx count: 81 
01 Aug 12:34:10 | Produced block 20433725 (0x753576...0e669e), diff: 0, tx count: 118 
01 Aug 12:34:10 | Improved post-merge block 20433725 (0x753576...0e669e), diff: 0, tx count: 118 
01 Aug 12:34:13 | Received new block:  20433725 (0xb92eee...8191d9) 
01 Aug 12:34:13 | Processed            20433725     |     51.64 ms  |  slot     12,322 ms | Gas gwei: 6.60 .. 7.83 (10.69) .. 131.60 
01 Aug 12:34:13 | - Block              12.87 MGas   |    162    txs |  calls  1,176 (136) | sload   5,036 | sstore  1,478 | create   0 
01 Aug 12:34:13 | - Block throughput  249.19 MGas/s |   3136.92 t/s |         19.36 Blk/s | recv        0 | proc        0 
01 Aug 12:34:13 | Received ForkChoice: Head: 20433725 (0xb92eee...8191d9), Safe: 20433684 (0x552cf7...f3bea7), Finalized: 20433652 (0x14f5c5...ce7995) 

I don't have any problem with mev-boost.

tersec commented 1 month ago

Example Nethermind logs from one of the Holesky fleet testnet nodes:

24 Jul 08:39:01 | Synced Chain Head to 1991217 (0x1a535b...40da9d) 
24 Jul 08:39:01 | Produced block 1991218 (0x5cbaeb...a11064), diff: 0, tx count: 5 
24 Jul 08:39:01 | Improved post-merge block 1991218 (0x5cbaeb...a11064), diff: 0, tx count: 5 
24 Jul 08:39:04 | Produced block 1991218 (0x1e3ea8...1dc5ce), diff: 0, tx count: 14 
24 Jul 08:39:04 | Improved post-merge block 1991218 (0x1e3ea8...1dc5ce), diff: 0, tx count: 14 
24 Jul 08:39:07 | Produced block 1991218 (0xb34b3f...27e351), diff: 0, tx count: 18 
24 Jul 08:39:07 | Improved post-merge block 1991218 (0xb34b3f...27e351), diff: 0, tx count: 18 
24 Jul 08:39:10 | Produced block 1991218 (0x56f51e...106121), diff: 0, tx count: 24 
24 Jul 08:39:10 | Improved post-merge block 1991218 (0x56f51e...106121), diff: 0, tx count: 24 
24 Jul 08:39:12 | GetPayloadV3 result: Hash: 0x56f51eba07a289ad39294cca440dcdb41e6070bcb22b6d0103ce3f1775106121
Number: 1991218
Parent: 0x1a535b38bf4e2636d387114b2077e219750a81f97605f1e1f3d0ed6bc340da9d
Beneficiary: 0x455e5aa18469bc6ccef49594645666c587a3a71b
Gas Limit: 30000000
Gas Used: 2697094
Timestamp: 1721810352
Extra Data: 4e65746865726d696e64
Difficulty: 0
Mix Hash: 0x081c7e03a082b1afdedf8005d44642427d13b18849be9981f0185f9a9b84a287
Nonce: 0
Uncles Hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347
Tx Root: 0x2e3b5625a5f30b0b7ac587604b26672f71f3d99e17e2cb47ad234916a4a5423d
Receipts Root: 0x4ee2d7ef22bef9d4961270c14233601140925e3d34236c4d5e2ea91962cc379a
State Root: 0xdee4a89bc435a8c97e174de1634a7a76e5d74d30a7c7d95f5780457b4b4d1c55
BaseFeePerGas: 8
WithdrawalsRoot: 0xbe3611aa65ce1787bdc6d425462f102962ecb0ed63421c6230c144498a27a6a8
ParentBeaconBlockRoot: 0x7a0b98ec46d2bba0a93cd4e665106fd295ec6e41423884bc73d48a85349a22f6
BlobGasUsed: 0
ExcessBlobGas: 0
IsPostMerge: True
TotalDifficulty: 1
. 
24 Jul 08:39:12 | Received New Block:  1991218 (0x56f51e...106121) 

In particular, the GetPayloadV3 result log.

Do you have any of those? If you don't, then as far as Nethermind saw, Nimbus asked it to create a block via forkchoiceUpdatedV3 but not to provide the results via getPayloadV3. If it didn't, there was nothing to compare it with, and this would be consistent with no Requesting engine payload logs, because that amounts to sending the EL getPayloadV3.

tersec commented 1 month ago

Oh, have a suspicion: you're probably using a validator client which isn't using produceBlockV3, the current API for this.

That API should trigger collectBids, but older beacon API endpoints such as produceBlindedBlock will only ever create the blinded block.

There's no beacon node fix-as-such for this. It's behaving according to spec, in this case. It's on the VC to compare things. But really, should be using produceBlockV3 anyway by now.

So, is this the case -- are you using a validator client, and if so, which/how is it configured regarding this?

mrzigha commented 1 month ago

Yes i'm using Nimbus, Teku, Lighthouse as validator client but i have this issue only with Nimbus as CL client.

tersec commented 1 month ago

The question here is which beacon API they're using.

If they're using produceBlindedBlock, this is exactly the expected result.

If they're using produceBlockV3, something is going awry.

So questions: