Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
mrzigha opened this issue Jul 26, 2024 · 8 comments
Open

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

mrzigha opened this issue Jul 26, 2024 · 8 comments

Comments

@mrzigha
Copy link

mrzigha commented Jul 26, 2024

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
Copy link
Contributor

tersec commented Jul 28, 2024

This already exists as Compared engine and builder block bids logging:

# There should always be an engine bid, and if payloadBuilderClient exists,
# not getting a builder bid is also an error. Do not report lack of builder
# when that's intentional. Replicate some of the nested if statements here,
# because that avoids entangling logging with other functionality. The logs
# here are inteded to clarify that, for example, when the builder API relay
# URL is provided for this validator, it's reasonable for Nimbus not to use
# it for every block.
if collectedBids.engineBid.isSome():
# Three cases: builder bid expected and absent, builder bid expected and
# present, and builder bid not expected.
if collectedBids.builderBid.isSome():
info "Compared engine and builder block bids",
localBlockValueBoost,
useBuilderBlock,
builderBlockValue =
toString(collectedBids.builderBid.value().executionPayloadValue, 10),
engineBlockValue =
toString(collectedBids.engineBid.value().executionPayloadValue, 10)
elif payloadBuilderClient.isNil:
discard # builder API not configured for this block
else:
info "Did not receive expected builder bid; using engine block",
engineBlockValue = collectedBids.engineBid.value().executionPayloadValue
else:
# Similar three cases: builder bid expected and absent, builder bid
# expected and present, and builder bid not expected. However, only
# the second is worth logging, because the other two result in this
# block being missed altogether, and with details logged elsewhere.
if collectedBids.builderBid.isSome:
info "Did not receive expected engine bid; using builder block",
builderBlockValue =
collectedBids.builderBid.value().executionPayloadValue

@mrzigha mrzigha closed this as completed Jul 29, 2024
@mrzigha mrzigha reopened this Aug 1, 2024
@mrzigha
Copy link
Author

mrzigha commented Aug 1, 2024

@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
Copy link
Contributor

tersec commented Aug 2, 2024

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:

info "Requesting engine payload",
beaconHead = shortLog(beaconHead.blck),
executionHead = shortLog(executionHead),
validatorIndex = validator_index,
feeRecipient = $feeRecipient

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:

else:
# Similar three cases: builder bid expected and absent, builder bid
# expected and present, and builder bid not expected. However, only
# the second is worth logging, because the other two result in this
# block being missed altogether, and with details logged elsewhere.
if collectedBids.builderBid.isSome:
info "Did not receive expected engine bid; using builder block",
builderBlockValue =
collectedBids.builderBid.value().executionPayloadValue

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
Copy link
Author

mrzigha commented Aug 2, 2024

@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
Copy link
Contributor

tersec commented Aug 2, 2024

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
Copy link
Contributor

tersec commented Aug 2, 2024

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
Copy link
Author

mrzigha commented Aug 5, 2024

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

@tersec
Copy link
Contributor

tersec commented Aug 12, 2024

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:

  • the Teku and LH clients, are they all connected to the same Nimbus BN? or, specifically, what VCs connect to this Nimbus BN, not just all the VCs you run in total?

  • Do the GetPayloadV3 result logs ever appear, or just don't appear in certain circumstances/when certain VCs request blocks (e.g., the Nimbus VC, or some other VC) from the Nimbus BN?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants