search

paradigmxyz / reth

Modular, contributor-friendly and blazing-fast implementation of the Ethereum protocol, in Rust
https://reth.rs/
Apache License 2.0
3.94k stars 1.18k forks source link

CL timeout with IncompleteMessage during sender recovery #6521

Closed Rjected closed 2 weeks ago

Rjected commented 9 months ago

Describe the bug

Recently experienced a timeout during holesky sender recovery using lighthouse 4.5.0 and reth alpha.17:

lighthouse:

Feb 09 21:57:00.964 ERRO Error updating deposit contract cache   error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: beacon
Feb 09 21:57:04.539 WARN Execution engine call failed            error: HttpClient(url: http://127.0.0.1:8551/, kind: timeout, detail: operation timed out), service: exec
Feb 09 21:57:04.549 WARN Error whilst processing payload status  error: Api { error: HttpClient(url: http://127.0.0.1:8551/, kind: timeout, detail: operation timed out) }, service: exec
Feb 09 21:57:06.002 WARN Head is optimistic                      execution_block_hash: 0xa527f59b0ffd53a372d251c70e197b001e4c23c8033086aa993ea480d7d5a1e4, info: chain not fully verified, block and attestation production disabled until execution engine syncs, service: slot_notifier
Feb 09 21:57:06.002 INFO Synced                                  slot: 967785, block:    …  empty, epoch: 30243, finalized_epoch: 30241, finalized_root: 0x26af…862b, exec_hash: 0xa527…a1e4 (unverified), peers: 72, service: slot_notifier
Feb 09 21:57:06.002 WARN Syncing deposit contract block cache    est_blocks_remaining: initializing deposits, service: slot_notifier
Feb 09 21:57:14.428 WARN Execution engine call failed            error: HttpClient(url: http://127.0.0.1:8551/, kind: timeout, detail: operation timed out), service: exec
Feb 09 21:57:14.428 WARN Error whilst processing payload status  error: Api { error: HttpClient(url: http://127.0.0.1:8551/, kind: timeout, detail: operation timed out) }, service: exec

reth:

2024-02-09T21:56:33.898069Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)
2024-02-09T21:56:41.747560Z DEBUG connection{remote_addr=127.0.0.1:49649 conn_id=19}: jsonrpsee_server::server: Accepting new connection 3/500
2024-02-09T21:56:43.054628Z  INFO reth::cli: Status connected_peers=7 freelist=13 stage=SenderRecovery checkpoint=423244 target=614700 stage_progress=None stage_eta=unknown
2024-02-09T21:56:44.169058Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)
2024-02-09T21:56:47.114201Z DEBUG discv4: evicting nodes due to failed pong num=0
2024-02-09T21:56:47.114306Z DEBUG discv4: evicting nodes due to failed lookup num=0
2024-02-09T21:56:47.114335Z DEBUG discv4: processing failed neighbours num=0
2024-02-09T21:56:47.198569Z DEBUG discv4: Failed to send datagram. to=18.180.179.220:0 err=Os { code: 49, kind: AddrNotAvailable, message: "Can't assign requested address" }
2024-02-09T21:56:47.358860Z DEBUG discv4: added after successful endpoint proof record=NodeRecord { address: 34.235.167.97, tcp_port: 30303, udp_port: 30303, id: 0x9760fb60c7fed13ccc6bd9103bed494fb1726b571b31d301818b98973db2440da595ce3115bccc703a7e651677e53ee2a2a08f17d9f92aa311dd2a833af75794 }
2024-02-09T21:56:47.383087Z DEBUG start_pending_outbound_session{remote_addr=57.128.75.192:30400}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.395351Z DEBUG discv4: added after successful endpoint proof record=NodeRecord { address: 3.138.100.244, tcp_port: 35021, udp_port: 35021, id: 0xc65f6d018dea9a4d4d689b6db4d4521b452d217defaf26ef1933030f46442a5e16f0c98c3f5f088d68ea73e0267b02dad175bccc7273f2132c2a64771f6c967e }
2024-02-09T21:56:47.399356Z DEBUG start_pending_outbound_session{remote_addr=62.167.90.44:30303}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.422651Z DEBUG discv4: added after successful endpoint proof record=NodeRecord { address: 3.71.53.239, tcp_port: 30303, udp_port: 30303, id: 0xebf4e8ce5d9181ac16855f85bd8de5bc62b380e04a2884ad73c1f1630fcda72b2f684fe0928df34d70162e806916da58de968df3b13cea9fe66a91211650ef9d }
2024-02-09T21:56:47.473951Z DEBUG discv4: added after successful endpoint proof record=NodeRecord { address: 34.228.82.188, tcp_port: 30303, udp_port: 30303, id: 0x491b0353f527a0300ef6f1ce377a74ac1d8a5b92df05e2e69283594850ecae8085d9c574929356462a04a2ba3f36018d46a9875d8289f2bb004c1cfb18f3de7c }
2024-02-09T21:56:47.499306Z DEBUG start_pending_outbound_session{remote_addr=67.203.1.170:30303}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.500639Z DEBUG start_pending_outbound_session{remote_addr=169.150.206.200:30303}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.506403Z DEBUG start_pending_outbound_session{remote_addr=130.61.171.137:30303}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.524078Z DEBUG start_pending_outbound_session{remote_addr=190.113.107.83:30404}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:56:47.524994Z DEBUG discv4: removed node node_id=0xc65f6d018dea9a4d4d689b6db4d4521b452d217defaf26ef1933030f46442a5e16f0c98c3f5f088d68ea73e0267b02dad175bccc7273f2132c2a64771f6c967e
2024-02-09T21:56:47.682235Z DEBUG discv4: added after successful endpoint proof record=NodeRecord { address: 15.235.145.220, tcp_port: 40303, udp_port: 40303, id: 0xde89d2050b90486b046e98ee3281006af176e95cb91ab0d428163e08dbca01b9d61900a143ba64bb72f297d6a3b22b35581f2e741f7dd8dad99908321d9fc268 }
2024-02-09T21:56:47.691719Z DEBUG net::session: failed to receive message err=P2PStreamError(Disconnected(TooManyPeers)) remote_peer_id=0x1cf7db662897dcd2af946fdd47e5b6d8273846e6a6bef4f1f3ec1f2b38c77c6a2382fb9409e43681c15cc043298d9476f2faa14c1adb805c15559e616ff4c361
2024-02-09T21:56:53.747871Z DEBUG connection{remote_addr=127.0.0.1:49749 conn_id=20}: jsonrpsee_server::server: Accepting new connection 3/500
2024-02-09T21:56:54.226630Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)
2024-02-09T21:57:02.225221Z DEBUG start_pending_outbound_session{remote_addr=35.209.100.35:30303}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:04.539872Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)
2024-02-09T21:57:04.546690Z DEBUG connection{remote_addr=127.0.0.1:49775 conn_id=21}: jsonrpsee_server::server: Accepting new connection 2/500
2024-02-09T21:57:07.113007Z DEBUG discv4: evicting nodes due to failed pong num=0
2024-02-09T21:57:07.113270Z DEBUG discv4: evicting nodes due to failed lookup num=0
2024-02-09T21:57:07.113306Z DEBUG discv4: processing failed neighbours num=0
2024-02-09T21:57:08.054783Z  INFO reth::cli: Status connected_peers=7 freelist=13 stage=SenderRecovery checkpoint=423244 target=614700 stage_progress=None stage_eta=unknown
2024-02-09T21:57:12.378676Z DEBUG start_pending_outbound_session{remote_addr=69.10.45.54:31100}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:12.562425Z DEBUG net::session: failed to receive message err=P2PStreamError(Disconnected(TooManyPeers)) remote_peer_id=0x61a4c0e9858f3afef9120f04064412715bbff99497df81903d48060a9da2c110121a347ad511bbeccb8601dce062d1dd7f5a97a7d1871d9c5b6a77b80f251795
2024-02-09T21:57:12.567075Z DEBUG start_pending_outbound_session{remote_addr=83.89.250.54:30404}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:12.569460Z DEBUG start_pending_outbound_session{remote_addr=95.223.119.241:31404}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:14.446273Z DEBUG connection{remote_addr=127.0.0.1:49800 conn_id=22}: jsonrpsee_server::server: Accepting new connection 3/500
2024-02-09T21:57:14.446813Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)
2024-02-09T21:57:17.454555Z DEBUG start_pending_outbound_session{remote_addr=184.148.155.101:30404}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:17.756267Z DEBUG connection{remote_addr=127.0.0.1:50019 conn_id=23}: jsonrpsee_server::server: Accepting new connection 3/500
2024-02-09T21:57:18.248801Z DEBUG start_pending_outbound_session{remote_addr=109.49.134.241:31404}: reth_eth_wire::p2pstream: error decompressing p2p message err=HeaderMismatch { expected_len: 577, got_len: 0 } msg=c104
2024-02-09T21:57:24.801026Z DEBUG jsonrpsee_server::server: HTTP serve connection failed hyper::Error(IncompleteMessage)

This goes away on its own but would be worth looking into

Steps to reproduce

Run lighthouse and reth, sync holesky

Node logs

No response

Platform(s)

Mac (Apple Silicon)

What version/commit are you on?

cd0a2f34bcdd0e4ce86c915d3299848c3ba18ac7

What database version are you on?

1

What type of node are you running?

Archive (default)

What prune config do you use, if any?

No response

If you've built Reth from source, provide the full command you used

No response

Code of Conduct

github-actions[bot] commented 8 months ago

This issue is stale because it has been open for 21 days with no activity.

quickchase commented 5 months ago

Related #7322

mattsse commented 2 weeks ago

closing as no longer relevant