search

prysmaticlabs / prysm

Go implementation of Ethereum proof of stake
https://www.offchainlabs.com/
GNU General Public License v3.0
3.41k stars 969 forks source link

Propose a block that does not contain any transactions #14126

Open artree222 opened 1 month ago

artree222 commented 1 month ago

On the mainnet, we are using the Prysm client to connect to the validator, but the validator proposed a block at slot 9297851 that did not contain any transactions. We hope the community can help us look into the reason for this.

The following is Prysm log:

time="2024-06-15 04:50:12" level=info msg="gRPC client connected to beacon node" addr="xx.xx.xx.xx:xx" prefix=rpc
time="2024-06-15 04:50:19" level=error msg="Could not handle p2p pubsub" error="could not validate blob data availability: context deadline waiting for blob sidecars slot: 9297847, BlockRoot: 0x70ee1d904f560baba0f959f07895ce14be2ec76a4a1d19672e4266976fed564a: context deadline exceeded" prefix=sync topic="/eth2/6a95a1a9/beacon_block/ssz_snappy"
time="2024-06-15 04:50:25" level=info msg="Synced new block" block=0x70ee1d90... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297847
time="2024-06-15 04:50:25" level=info msg="Finished applying state transition" attestations=87 kzgCommitmentCount=4 payloadHash=0x27894e8867a6 prefix=blockchain slot=9297847 syncBitsCount=509 txCount=173
time="2024-06-15 04:50:26" level=info msg="Synced new block" block=0x407d5564... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297848
time="2024-06-15 04:50:26" level=info msg="Finished applying state transition" attestations=128 kzgCommitmentCount=6 payloadHash=0x609356e79ce1 prefix=blockchain slot=9297848 syncBitsCount=510 txCount=212
time="2024-06-15 04:50:26" level=info msg="Synced new block" block=0x25d6d82f... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297849
time="2024-06-15 04:50:26" level=info msg="Finished applying state transition" attestations=73 kzgCommitmentCount=6 payloadHash=0x75a8302f9c54 prefix=blockchain slot=9297849 syncBitsCount=508 txCount=191
time="2024-06-15 04:50:29" level=info msg="Synced new block" block=0x8f13baed... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297850
time="2024-06-15 04:50:29" level=info msg="Finished applying state transition" attestations=72 kzgCommitmentCount=6 payloadHash=0x9f200f5067e3 prefix=blockchain slot=9297850 syncBitsCount=510 txCount=100
time="2024-06-15 04:50:35" level=info msg="Begin building block" prefix="rpc/validator" sinceSlotStartTime=23.423581ms slot=9297851
time="2024-06-15 04:50:35" level=warning msg="could not find tracked proposer index" headRoot=0x8f13baed2056ca9fb0628c9d62c1ca66bbea18dbccfc16664c71202cb5fe627b slot=9297851 validatorIndex=275839
time="2024-06-15 04:50:35" level=info msg="Finished building block" prefix="rpc/validator" sinceSlotStartTime=94.263226ms slot=9297851 validator=275839
time="2024-06-15 04:50:35" level=info msg="Synced new block" block=0x1426caa4... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297851
time="2024-06-15 04:50:35" level=info msg="Finished applying state transition" attestations=128 payloadHash=0x0ed10159339f prefix=blockchain slot=9297851 syncBitsCount=509 txCount=0
time="2024-06-15 04:50:50" level=info msg="Synced new block" block=0xcd282755... epoch=290557 finalizedEpoch=290555 finalizedRoot=0x3ff7eb5d... prefix=blockchain slot=9297852
time="2024-06-15 04:50:50" level=info msg="Finished applying state transition" attestations=128 kzgCommitmentCount=3 payloadHash=0xba5b04bbaaac prefix=blockchain slot=9297852 syncBitsCount=512 txCount=349

The following is Geth log:

INFO [06-15|04:50:26.147] Imported new potential chain segment     number=20,092,543 hash=609356..78ce57 blocks=1 txs=212  mgas=20.614 elapsed=255.104ms    mgasps=80.806  snapdiffs=6.97MiB  triedirty=1022.22MiB
INFO [06-15|04:50:26.220] Chain head was updated                   number=20,092,543 hash=609356..78ce57 root=511031..341251 elapsed=4.454392ms
INFO [06-15|04:50:26.431] Imported new potential chain segment     number=20,092,544 hash=75a830..e32222 blocks=1 txs=191  mgas=16.086 elapsed=145.673ms    mgasps=110.425 snapdiffs=7.02MiB  triedirty=1022.36MiB
INFO [06-15|04:50:26.530] Chain head was updated                   number=20,092,544 hash=75a830..e32222 root=d4a287..574610 elapsed=3.079023ms
INFO [06-15|04:50:29.738] Imported new potential chain segment     number=20,092,545 hash=9f200f..057d36 blocks=1 txs=100  mgas=6.230  elapsed=84.656ms     mgasps=73.594  snapdiffs=7.04MiB  triedirty=1022.67MiB
INFO [06-15|04:50:29.849] Chain head was updated                   number=20,092,545 hash=9f200f..057d36 root=6b68ff..7c5271 elapsed=1.375609ms
INFO [06-15|04:50:35.061] Starting work on payload                 id=0x03404ae851fd05ab
INFO [06-15|04:50:35.083] Stopping work on payload                 id=0x03404ae851fd05ab reason=delivery
INFO [06-15|04:50:35.184] Imported new potential chain segment     number=20,092,546 hash=0ed101..48ab7a blocks=1 txs=0    mgas=0.000  elapsed=28.942ms     mgasps=0.000   snapdiffs=7.02MiB  triedirty=1020.20MiB
INFO [06-15|04:50:35.308] Chain head was updated                   number=20,092,546 hash=0ed101..48ab7a root=8a4e78..43a5c9 elapsed="84.351µs"
INFO [06-15|04:50:49.584] Imported new potential chain segment     number=20,092,547 hash=ba5b04..b0264d blocks=1 txs=349  mgas=29.992 elapsed=338.006ms    mgasps=88.732  snapdiffs=7.10MiB  triedirty=1021.25MiB
INFO [06-15|04:50:50.962] Chain head was updated                   number=20,092,547 hash=ba5b04..b0264d root=b3abf4..c09bbd elapsed=5.953949ms

The following is Mev log:

time="2024-06-15T04:50:05.892+08:00" level=info msg="http: GET / 200" duration=0.000034 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://boost-relay.flashbots.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://mainnet-relay.securerpc.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://bloxroute.max-profit.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://agnostic-relay.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://relay.ultrasound.money/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://relay.edennetwork.io/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://aestus.live/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.19+08:00" level=debug msg="checking relay status" url="https://bloxroute.regulated.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.374+08:00" level=debug msg="relay status OK" url="https://agnostic-relay.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.408+08:00" level=debug msg="relay status OK" url="https://bloxroute.max-profit.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.41+08:00" level=debug msg="relay status OK" url="https://relay.edennetwork.io/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.427+08:00" level=debug msg="relay status OK" url="https://relay.ultrasound.money/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.465+08:00" level=debug msg="relay status OK" url="https://boost-relay.flashbots.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.473+08:00" level=debug msg="relay status OK" url="https://bloxroute.regulated.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.502+08:00" level=debug msg="relay status OK" url="https://aestus.live/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.893+08:00" level=debug msg="relay status OK" url="https://mainnet-relay.securerpc.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:09.893+08:00" level=info msg="http: GET /eth/v1/builder/status 200" duration=0.702974 method=GET path=/eth/v1/builder/status status=200 version=1.7
time="2024-06-15T04:50:15.883+08:00" level=info msg="http: GET / 200" duration=0.000030 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:50:25.908+08:00" level=info msg="http: GET / 200" duration=0.000038 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://boost-relay.flashbots.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://mainnet-relay.securerpc.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://relay.edennetwork.io/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://relay.ultrasound.money/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://aestus.live/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://bloxroute.regulated.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://bloxroute.max-profit.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.566+08:00" level=debug msg="checking relay status" url="https://agnostic-relay.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.757+08:00" level=debug msg="relay status OK" url="https://agnostic-relay.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.784+08:00" level=debug msg="relay status OK" url="https://relay.ultrasound.money/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.785+08:00" level=debug msg="relay status OK" url="https://bloxroute.max-profit.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.787+08:00" level=debug msg="relay status OK" url="https://relay.edennetwork.io/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.837+08:00" level=debug msg="relay status OK" url="https://boost-relay.flashbots.net/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:30.876+08:00" level=debug msg="relay status OK" url="https://aestus.live/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:31.139+08:00" level=debug msg="relay status OK" url="https://bloxroute.regulated.blxrbdn.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:31.243+08:00" level=debug msg="relay status OK" url="https://mainnet-relay.securerpc.com/eth/v1/builder/status" version=1.7
time="2024-06-15T04:50:31.244+08:00" level=info msg="http: GET /eth/v1/builder/status 200" duration=0.677619 method=GET path=/eth/v1/builder/status status=200 version=1.7
time="2024-06-15T04:50:35.881+08:00" level=info msg="http: GET / 200" duration=0.000040 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:50:45.885+08:00" level=info msg="http: GET / 200" duration=0.000034 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:50:55.883+08:00" level=info msg="http: GET / 200" duration=0.000033 method=GET path=/ status=200 version=1.7
time="2024-06-15T04:51:05.882+08:00" level=info msg="http: GET / 200" duration=0.000032 method=GET path=/ status=200 version=1.7
james-prysm commented 1 month ago

What version was this and what flags were you using?

artree222 commented 1 month ago

What version was this and what flags were you using? prysm v5.0.2 geth v1.13.15

james-prysm commented 1 month ago

how about flags? I do see a warning here could not find tracked proposer index which makes me believe there's a chance the fee recipient wasn't set here ( defaulting to beacon node's) but it doesn't look like it was set and resulted in 0x0000000000000000000000000000000000000000.

this could indicate a few things, either your validator was connected to a new beacon node and didn't call the push proposer settings endpoint yet, or a validator was added after the start of the epoch and proposed immediately ( we have some improvements coming to resolve this edge case)

this doesn't answer why no transactions were included though ...

james-prysm commented 1 month ago

After some conversation with the team, it seems like the transactions missed can happen in 2 situations 1.if you get a reorg in the last second you will produce a block without txs 2.if you have a proposer id miss because the FCU with the attributes was never sent. This happens if your validator is not tracked and is unable to send meta data to the local execution client.

what must has happened is something has caused your validator to not register with the mev boost/ call the push proposer settings endpoint on the beacon node which missed the tracked validators, because the validator was not registered with the mevbuilder it must have defaulted to local build but local didn't have the validator tracked either resulting the above.

The push proposer settings/validator registration happens at the start of every epoch, is there more context on how that validator may have not been updated when being added?