log sync failure

Question

log sync failure

Closed this issue 6 months ago · 1 comments

i use my own validator node rpc for the storage node. my validator node rpc is synced well. but my storage node can't sync. here's the logs:

2024-05-30T12:30:20.605336Z INFO zgs_node::client::environment: Internal shutdown received reason="log sync failure"
2024-05-30T12:30:20.605356Z INFO zgs_node: Shutting down... reason=Failure("log sync failure")
2024-05-30T12:30:39.469803Z INFO zgs_node: Starting services...
2024-05-30T12:30:39.519665Z DEBUG storage::log_store::log_manager: LogManager::new() with chunk_list_len=0 start_tx_seq=None last_chunk=0
2024-05-30T12:30:39.520453Z DEBUG network::service: Loaded network key from disk.
2024-05-30T12:30:39.521387Z DEBUG network::discovery::enr: ENR loaded from disk file="network/enr.dat"
2024-05-30T12:30:39.521745Z INFO network::service: Libp2p Starting peer_id=16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB bandwidth_config=3-Average
2024-05-30T12:30:39.521778Z DEBUG network::service: Attempting to open listening ports address=0.0.0.0 tcp_port=1234 udp_port=1234
2024-05-30T12:30:39.521966Z INFO network::nat: UPnP Attempting to initialise routes
2024-05-30T12:30:39.522568Z INFO network::discovery: ENR Initialised enr=enr:-Hy4QBIoXiK2jg5cplb6ykQ7uKwbAb35BJoXkBzFjT9XYS0sSQUPuPzRLtP8ecVOSYYCWdJL3aQasUxkqd9kf9u3XskBgmlkgnY0iXNlY3AyNTZrMaEC1Dgr5q7Ptu2lhCAkr2gQRiqqeIZjdNudydjE9DNkm-yDdGNwggTS seq=1 id=0xa8af..5bd2 ip=None udp=None tcp=Some(1234) udp4_socket=None
2024-05-30T12:30:39.523679Z DEBUG network::discovery: Discovery service started
2024-05-30T12:30:39.523694Z INFO network::discovery: Contacting Multiaddr boot-nodes for their ENR
2024-05-30T12:30:39.523826Z INFO discv5::service: Discv5 Service started
2024-05-30T12:30:39.523893Z DEBUG discv5::service: Sending RPC Request: id: 6e492ab7c0a72d47: FINDNODE Request: distance: [0] to node: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:30:39.523906Z DEBUG discv5::service: Sending RPC Request: id: 592c653507584bcd: FINDNODE Request: distance: [0] to node: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:30:39.523956Z DEBUG discv5::handler: Handler Starting
2024-05-30T12:30:39.523987Z DEBUG discv5::socket::send: Send handler starting
2024-05-30T12:30:39.524018Z DEBUG discv5::socket::recv: Recv handler starting
2024-05-30T12:30:39.883850Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0xc909..1134, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:30:39.883988Z DEBUG network::discovery: Adding node to routing table node_id=0xc909..1134 peer_id=16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps ip=None udp=None tcp=Some(1234)
2024-05-30T12:30:39.884005Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:30:39.884009Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/54.219.26.22/udp/1234/p2p/16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps error=ENR has no UDP socket to connect to
2024-05-30T12:30:39.900506Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0x3ec9..8916, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:30:39.901136Z DEBUG network::discovery: Adding node to routing table node_id=0x3ec9..8916 peer_id=16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS ip=None udp=None tcp=Some(1234)
2024-05-30T12:30:39.901170Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:30:39.901181Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/52.52.127.117/udp/1234/p2p/16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS error=ENR has no UDP socket to connect to
2024-05-30T12:30:39.901193Z DEBUG network::discovery: Starting a peer discovery request target_peers=16
2024-05-30T12:30:39.901537Z INFO network::service: Listening established address=/ip4/0.0.0.0/tcp/1234/p2p/16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB
2024-05-30T12:30:39.901573Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_file/ssz_snappy
2024-05-30T12:30:39.901578Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_chunks/ssz_snappy
2024-05-30T12:30:39.901580Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_file/ssz_snappy
2024-05-30T12:30:39.901584Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_chunks/ssz_snappy
2024-05-30T12:30:39.901586Z INFO network::service: Subscribed to topics topics=[FindFile, FindChunks, AnnounceFile, AnnounceChunks]
2024-05-30T12:30:39.901712Z DEBUG sync::service: Starting sync service
2024-05-30T12:30:40.743002Z WARN log_entry_sync::sync_manager: unable to get finalized block: Err(JsonRpcClientError(JsonRpcError(JsonRpcError { code: -32601, message: "Method not found", data: None })))
2024-05-30T12:30:40.884943Z DEBUG discv5::service: RPC Request timed out. id: 79e8a4df90a30d6b
2024-05-30T12:30:40.902271Z DEBUG discv5::service: RPC Request timed out. id: 4ae6ab6e4372a3bc
2024-05-30T12:30:41.068135Z ERROR zgs_node: Failed to start zgs node reason=Unable to get chain_id: JsonRpcClientError(JsonRpcError(JsonRpcError { code: -32601, message: "Method not found", data: None }))
2024-05-30T12:30:41.068220Z INFO discv5::service: Discv5 Service shutdown
2024-05-30T12:30:41.068423Z INFO zgs_node::client::environment: Internal shutdown received reason="Failed to start zgs node"
2024-05-30T12:30:41.068453Z INFO zgs_node: Shutting down... reason=Failure("Failed to start zgs node")
2024-05-30T12:30:41.068478Z DEBUG discv5::socket::recv: Recv handler shutdown
2024-05-30T12:30:41.068488Z DEBUG discv5::socket::send: Send handler shutdown
2024-05-30T12:30:41.068514Z DEBUG task_executor: Async task shutdown, exit received task="log_reload"
2024-05-30T12:30:59.974765Z INFO zgs_node: Starting services...
2024-05-30T12:31:00.025068Z DEBUG storage::log_store::log_manager: LogManager::new() with chunk_list_len=0 start_tx_seq=None last_chunk=0
2024-05-30T12:31:00.025603Z DEBUG network::service: Loaded network key from disk.
2024-05-30T12:31:00.026704Z DEBUG network::discovery::enr: ENR loaded from disk file="network/enr.dat"
2024-05-30T12:31:00.027085Z INFO network::service: Libp2p Starting peer_id=16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB bandwidth_config=3-Average
2024-05-30T12:31:00.027121Z DEBUG network::service: Attempting to open listening ports address=0.0.0.0 tcp_port=1234 udp_port=1234
2024-05-30T12:31:00.027190Z INFO network::nat: UPnP Attempting to initialise routes
2024-05-30T12:31:00.027789Z INFO network::discovery: ENR Initialised enr=enr:-Hy4QBIoXiK2jg5cplb6ykQ7uKwbAb35BJoXkBzFjT9XYS0sSQUPuPzRLtP8ecVOSYYCWdJL3aQasUxkqd9kf9u3XskBgmlkgnY0iXNlY3AyNTZrMaEC1Dgr5q7Ptu2lhCAkr2gQRiqqeIZjdNudydjE9DNkm-yDdGNwggTS seq=1 id=0xa8af..5bd2 ip=None udp=None tcp=Some(1234) udp4_socket=None
2024-05-30T12:31:00.028959Z DEBUG network::discovery: Discovery service started
2024-05-30T12:31:00.028969Z INFO network::discovery: Contacting Multiaddr boot-nodes for their ENR
2024-05-30T12:31:00.029129Z INFO discv5::service: Discv5 Service started
2024-05-30T12:31:00.029150Z DEBUG discv5::service: Sending RPC Request: id: 4d44aa7a4e1c05cc: FINDNODE Request: distance: [0] to node: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:31:00.029163Z DEBUG discv5::service: Sending RPC Request: id: c1c982c3e6f18684: FINDNODE Request: distance: [0] to node: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:31:00.029191Z DEBUG discv5::socket::recv: Recv handler starting
2024-05-30T12:31:00.029199Z DEBUG discv5::handler: Handler Starting
2024-05-30T12:31:00.029264Z DEBUG discv5::socket::send: Send handler starting
2024-05-30T12:31:00.389140Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0xc909..1134, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:31:00.389826Z DEBUG network::discovery: Adding node to routing table node_id=0xc909..1134 peer_id=16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps ip=None udp=None tcp=Some(1234)
2024-05-30T12:31:00.389853Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:31:00.389915Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/54.219.26.22/udp/1234/p2p/16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps error=ENR has no UDP socket to connect to
2024-05-30T12:31:00.406628Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0x3ec9..8916, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:31:00.407218Z DEBUG network::discovery: Adding node to routing table node_id=0x3ec9..8916 peer_id=16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS ip=None udp=None tcp=Some(1234)
2024-05-30T12:31:00.407236Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:31:00.407245Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/52.52.127.117/udp/1234/p2p/16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS error=ENR has no UDP socket to connect to
2024-05-30T12:31:00.407260Z DEBUG network::discovery: Starting a peer discovery request target_peers=16
2024-05-30T12:31:00.407617Z INFO network::service: Listening established address=/ip4/0.0.0.0/tcp/1234/p2p/16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB
2024-05-30T12:31:00.407657Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_file/ssz_snappy
2024-05-30T12:31:00.407662Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_chunks/ssz_snappy
2024-05-30T12:31:00.407665Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_file/ssz_snappy
2024-05-30T12:31:00.407668Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_chunks/ssz_snappy
2024-05-30T12:31:00.407670Z INFO network::service: Subscribed to topics topics=[FindFile, FindChunks, AnnounceFile, AnnounceChunks]
2024-05-30T12:31:00.407781Z DEBUG sync::service: Starting sync service
2024-05-30T12:31:01.390090Z DEBUG discv5::service: RPC Request timed out. id: a3fbb53a306e072a
2024-05-30T12:31:01.408304Z DEBUG discv5::service: RPC Request timed out. id: 9f1bdf9bb6309ef4
2024-05-30T12:31:01.640498Z ERROR zgs_node: Failed to start zgs node reason=Unable to get chain_id: JsonRpcClientError(JsonRpcError(JsonRpcError { code: -32601, message: "Method not found", data: None }))
2024-05-30T12:31:01.640556Z INFO discv5::service: Discv5 Service shutdown
2024-05-30T12:31:01.640842Z DEBUG discv5::socket::recv: Recv handler shutdown
2024-05-30T12:31:01.640821Z INFO zgs_node::client::environment: Internal shutdown received reason="Failed to start zgs node"
2024-05-30T12:31:01.640858Z INFO zgs_node: Shutting down... reason=Failure("Failed to start zgs node")
2024-05-30T12:31:20.476222Z INFO zgs_node: Starting services...
2024-05-30T12:31:20.515538Z DEBUG storage::log_store::log_manager: LogManager::new() with chunk_list_len=0 start_tx_seq=None last_chunk=0
2024-05-30T12:31:20.516087Z DEBUG network::service: Loaded network key from disk.
2024-05-30T12:31:20.517042Z DEBUG network::discovery::enr: ENR loaded from disk file="network/enr.dat"
2024-05-30T12:31:20.517320Z INFO network::service: Libp2p Starting peer_id=16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB bandwidth_config=3-Average
2024-05-30T12:31:20.517343Z DEBUG network::service: Attempting to open listening ports address=0.0.0.0 tcp_port=1234 udp_port=1234
2024-05-30T12:31:20.517380Z INFO network::nat: UPnP Attempting to initialise routes
2024-05-30T12:31:20.517909Z INFO network::discovery: ENR Initialised enr=enr:-Hy4QBIoXiK2jg5cplb6ykQ7uKwbAb35BJoXkBzFjT9XYS0sSQUPuPzRLtP8ecVOSYYCWdJL3aQasUxkqd9kf9u3XskBgmlkgnY0iXNlY3AyNTZrMaEC1Dgr5q7Ptu2lhCAkr2gQRiqqeIZjdNudydjE9DNkm-yDdGNwggTS seq=1 id=0xa8af..5bd2 ip=None udp=None tcp=Some(1234) udp4_socket=None
2024-05-30T12:31:20.518751Z DEBUG network::discovery: Discovery service started
2024-05-30T12:31:20.518763Z INFO network::discovery: Contacting Multiaddr boot-nodes for their ENR
2024-05-30T12:31:20.518897Z INFO discv5::service: Discv5 Service started
2024-05-30T12:31:20.518897Z DEBUG discv5::handler: Handler Starting
2024-05-30T12:31:20.518915Z DEBUG discv5::service: Sending RPC Request: id: 94a73e18bb0199da: FINDNODE Request: distance: [0] to node: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:31:20.518923Z DEBUG discv5::service: Sending RPC Request: id: 77a12d98f549a1a5: FINDNODE Request: distance: [0] to node: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:31:20.518935Z DEBUG discv5::socket::recv: Recv handler starting
2024-05-30T12:31:20.518967Z DEBUG discv5::socket::send: Send handler starting
2024-05-30T12:31:20.878559Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0xc909..1134, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0xc909..1134, addr: 54.219.26.22:1234
2024-05-30T12:31:20.878661Z DEBUG network::discovery: Adding node to routing table node_id=0xc909..1134 peer_id=16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps ip=None udp=None tcp=Some(1234)
2024-05-30T12:31:20.878677Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:31:20.878681Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/54.219.26.22/udp/1234/p2p/16Uiu2HAmTVDGNhkHD98zDnJxQWu3i1FL1aFYeh9wiQTNu4pDCgps error=ENR has no UDP socket to connect to
2024-05-30T12:31:20.896223Z DEBUG discv5::service: Received RPC response: NODES: total: 1, Nodes: [ENR: NodeId: 0x3ec9..8916, IpV4 Socket: None IpV6 Socket: None] to request: FINDNODE Request: distance: [0] from: Node: 0x3ec9..8916, addr: 52.52.127.117:1234
2024-05-30T12:31:20.896802Z DEBUG network::discovery: Adding node to routing table node_id=0x3ec9..8916 peer_id=16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS ip=None udp=None tcp=Some(1234)
2024-05-30T12:31:20.896837Z WARN discv5::discv5: ENR attempted to be added without a UDP socket has been ignored
2024-05-30T12:31:20.896853Z ERROR network::discovery: Could not add peer to the local routing table addr=/ip4/52.52.127.117/udp/1234/p2p/16Uiu2HAkzRjxK2gorngB1Xq84qDrT4hSVznYDHj6BkbaE4SGx9oS error=ENR has no UDP socket to connect to
2024-05-30T12:31:20.896881Z DEBUG network::discovery: Starting a peer discovery request target_peers=16
2024-05-30T12:31:20.897260Z INFO network::service: Listening established address=/ip4/0.0.0.0/tcp/1234/p2p/16Uiu2HAm9i66Bwa2rNpHBzVAzLi248gRQQqbfXG1KAiCeHkkEJGB
2024-05-30T12:31:20.897294Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_file/ssz_snappy
2024-05-30T12:31:20.897299Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/find_chunks/ssz_snappy
2024-05-30T12:31:20.897301Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_file/ssz_snappy
2024-05-30T12:31:20.897305Z DEBUG network::behaviour: Subscribed to topic topic=/eth2/announce_chunks/ssz_snappy
2024-05-30T12:31:20.897307Z INFO network::service: Subscribed to topics topics=[FindFile, FindChunks, AnnounceFile, AnnounceChunks]
2024-05-30T12:31:20.897407Z DEBUG sync::service: Starting sync service
2024-05-30T12:31:21.753827Z WARN log_entry_sync::sync_manager: unable to get finalized block: Err(JsonRpcClientError(JsonRpcError(JsonRpcError { code: -32601, message: "Method not found", data: None })))
2024-05-30T12:31:21.880854Z DEBUG discv5::service: RPC Request timed out. id: 003ce4b893ae5033
2024-05-30T12:31:21.898164Z DEBUG discv5::service: RPC Request timed out. id: acfc4418baf750c1
2024-05-30T12:31:22.163848Z ERROR log_entry_sync::sync_manager: log sync failure: e=(code: -32601, message: Method not found, data: None)

Stack backtrace:
0: anyhow::error::<impl core::convert::From for anyhow::Error>::from
1: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
2: <futures_util::future::select::Select<A,B> as core::future::future::Future>::poll
3: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
4: <futures_util::future::future::flatten::Flatten<Fut,::Output> as core::future::future::Future>::poll
5: tokio::runtime::task::core::Core<T,S>::poll
6: tokio::runtime::task::harness::Harness<T,S>::poll
7: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
8: tokio::runtime::scheduler::multi_thread::worker::Context::run
9: tokio::runtime::context::scoped::Scoped::set
10: tokio::runtime::context::runtime::enter_runtime
11: tokio::runtime::scheduler::multi_thread::worker::run
12: <tokio::runtime::blocking::task::BlockingTask as core::future::future::Future>::poll
13: tokio::runtime::task::core::Core<T,S>::poll
14: tokio::runtime::task::harness::Harness<T,S>::poll
15: tokio::runtime::blocking::pool::Inner::run
16: std::sys_common::backtrace::__rust_begin_short_backtrace
17: core::ops::function::FnOnce::call_once{{vtable.shim}}
18: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce>::call_once
at /build/rustc-Px5Ywq/rustc-1.75.0+dfsg0ubuntu1/library/alloc/src/boxed.rs:2007:9
19: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce>::call_once
at /build/rustc-Px5Ywq/rustc-1.75.0+dfsg0ubuntu1/library/alloc/src/boxed.rs:2007:9
20: std::sys::unix::thread::Thread::new::thread_start
at /build/rustc-Px5Ywq/rustc-1.75.0+dfsg0ubuntu1/library/std/src/sys/unix/thread.rs:108:17
21:
22:

Answer 1 · 2024-06-05T04:30:28.000Z

fixed. need to add JSON-rpc not the rpc. JSON-rpc default port is 8545