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

Rococo <> Wococo bridge hub relay disconnects from our RBH node #1785

Closed
svyatonik opened this issue Jan 19, 2023 · 12 comments · Fixed by #1927 or #1941
Closed

Rococo <> Wococo bridge hub relay disconnects from our RBH node #1785

svyatonik opened this issue Jan 19, 2023 · 12 comments · Fixed by #1927 or #1941
Assignees
Labels
A-bug Something isn't working

Comments

@svyatonik
Copy link
Contributor

Some logs:

2023-01-19 14:46:49 | [Wococo_to_BridgeHubRococo_Parachains] 2023-01-19 11:46:49 +00 WARN bridge Wococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
-- | -- | --
  |   | 2023-01-19 14:46:48 | [Rococo_to_BridgeHubWococo_Parachains] 2023-01-19 11:46:48 +00 WARN bridge Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | 2023-01-19 14:46:44 | [Wococo_to_BridgeHubRococo_Sync] 2023-01-19 11:46:44 +00 INFO bridge Synced 4030136 of 4030136 headers |  
  |   | 2023-01-19 14:46:43 | 2023-01-19 11:46:43 +00 WARN rustls::check Received a ServerHelloDone handshake message while expecting [CertificateRequest] |  
...
  |   | 2023-01-19 14:46:42 | 2023-01-19 11:46:42 +00 WARN rustls::check Received a ServerHelloDone handshake message while expecting [CertificateRequest]
@svyatonik svyatonik added the A-bug Something isn't working label Jan 19, 2023
@svyatonik svyatonik self-assigned this Jan 19, 2023
@svyatonik
Copy link
Contributor Author

svyatonik commented Jan 19, 2023

Seems like Received a ServerHelloDone handshake message while expecting [CertificateRequest] isn't a problem. And a real problem is the "connection closed" thing. The RPC node we connect to has following in its logs:

2023-01-19 16:48:06 | 2023-01-19 13:48:06 ✨ Imported #4031561 (0xc632…9264) |  
-- | -- | --
  |   | 2023-01-19 16:48:04 | unexpected end of file) |  
  |   | 2023-01-19 16:48:04 | Caused by: |  
  |   | 2023-01-19 16:48:04 |   |  
  |   | 2023-01-19 16:48:04 | 2023-01-19 13:48:04 Rejected connection: Transport(i/o error: unexpected end of file |  
  |   | 2023-01-19 16:48:04 | 2023-01-19 13:48:04 Accepting new connection 8/100

Is that the RPC connection (the "Accepting new connection 8/100" comes from jsonrpsee)? Why there's unexpected end of file (some decoding fails?)?

Trying to reproduce locally

@svyatonik
Copy link
Contributor Author

When it's all started (relay logs):

[Rococo_to_BridgeHubWococo_Sync] 2023-01-04 17:00:19 +00 ERROR bridge Finality sync loop iteration has failed with error: Source(RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed"))) |  
-- | --
  |   | [Rococo_to_BridgeHubWococo_Parachains] 2023-01-04 17:00:13 +00 WARN bridge Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | 2023-01-04 17:00:11 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  
  |   | [Wococo_to_BridgeHubRococo_Sync] 2023-01-04 17:00:08 +00 ERROR bridge Finality sync loop iteration has failed with error: Target(RpcError(Call(Custom(ErrorObject { code: ServerError(1010), message: "Invalid Transaction", data: Some(RawValue("Inability to pay some fees (e.g. account balance too low)")) })))) |  
  |   | 2023-01-04 17:00:08 +00 ERROR bridge Failed to send transaction to BridgeHubRococo node: Call(Custom(ErrorObject { code: ServerError(1010), message: "Invalid Transaction", data: Some(RawValue("Inability to pay some fees (e.g. account balance too low)")) })) |  
  |   | 2023-01-04 17:00:07 +00 WARN rustls::check Received a ServerHelloDone handshake message while expecting [CertificateRequest] |  
  |   | 2023-01-04 17:00:01 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  
  |   | [Rococo_to_BridgeHubWococo_Parachains] 2023-01-04 16:59:57 +00 WARN bridge Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | 2023-01-04 16:59:51 +00 WARN rustls::check Received a ServerHelloDone handshake message while expecting [CertificateRequest] |  
  |   | 2023-01-04 16:59:51 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  
  |   | 2023-01-04 16:59:43 +00 ERROR bridge [BridgeHubRococo-to-BridgeHubWococo-on-demand-parachain] Failed to read relay data from Rococo client: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | [Rococo_to_BridgeHubWococo_Parachains] 2023-01-04 16:59:41 +00 WARN bridge Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | 2023-01-04 16:59:41 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  
  |   | 2023-01-04 16:59:41 +00 ERROR bridge [Rococo-to-BridgeHubWococo-on-demand-headers] Failed to read best finalized source header from source: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) |  
  |   | 2023-01-04 16:59:39 +00 WARN jsonrpsee_core::client::async_client Transport(WebSocket connection error: connection closed |  
first appearance ->>>  |   | 2023-01-04 16:59:39 +00 ERROR jsonrpsee_core::client::async_client Error: Connection(Closed) terminating client |  
  |   | [Rococo_to_BridgeHubWococo_Sync] 2023-01-04 16:59:37 +00 ERROR bridge Finality sync loop iteration has failed with error: Target(RpcError(Call(Custom(ErrorObject { code: ServerError(1010), message: "Invalid Transaction", data: Some(RawValue("Inability to pay some fees (e.g. account balance too low)")) })))) |  
  |   | 2023-01-04 16:59:37 +00 ERROR bridge Failed to send transaction to BridgeHubWococo node: Call(Custom(ErrorObject { code: ServerError(1010), message: "Invalid Transaction", data: Some(RawValue("Inability to pay some fees (e.g. account balance too low)")) })) |  
  |   | 2023-01-04 16:59:31 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  
  |   | 2023-01-04 16:59:21 +00 ERROR bridge [BridgeHubWococo-to-BridgeHubRococo-on-demand-parachain] Failed to read relay data from Wococo client: RpcError(Call(Custom(ErrorObject { code: ServerError(-32000), message: "Client error: UnknownBlock: State already discarded for BlockId::Hash(0x2edff44b46f7278dad8b22661a6fccd2c77719be8a4f194239cba2d34021b408)", data: None }))) |  

@svyatonik
Copy link
Contributor Author

The issue is gone - it should have been fixed in one of referenced PRs. Still - I'm not sure if issue that I've originally described (i.e. when we are actually unable to reconnect) exist and whether it can be reproduced.

@svyatonik svyatonik reopened this Mar 2, 2023
@svyatonik
Copy link
Contributor Author

#1677 (comment)

@serban300
Copy link
Collaborator

serban300 commented Mar 2, 2023

Locally I'm getting a more specific error:

[BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] 2023-03-02 10:23:00 +00 ERROR bridge Error submitting proof BridgeHubWococo::MessagesDelivery: RpcError(Call(Custom(ErrorObject { code: ServerError(1010), message: "Invalid Transaction", data: Some(RawValue("Inability to pay some fees (e.g. account balance too low)")) }))). Retrying in 0.368770155

So maybe the "Networking or low-level protocol error: WebSocket connection error: connection closed" is caused by something in the remote environment (the host kernel, the docker container, etc)

@svyatonik
Copy link
Contributor Author

@serban300 No, that isn't what I see in logs. Are you sure you're using the same accounts (locally) as our relayer does? I can see the balances are not zero there: https://grafana.parity-mgmt.parity.io/d/UFsgbJtVz/bridgehubrococo-bridgehubwococo-maintenance-00000001?orgId=1

@serban300
Copy link
Collaborator

You might be right. Checking. I don't remember where I took these accounts from. I had this debugging env setup some time ago when investigating another issue

@serban300
Copy link
Collaborator

Yes, sorry, I was using a different account. When running the relayer locally, it just works

@svyatonik
Copy link
Contributor Author

svyatonik commented Mar 2, 2023

So "important" lines from tonight log:

Relay first aborts:

2023-03-02T02:49:00Z {pod="bridges-common-relay/bridges-common-relay-7f96994fb5-r6z5r"} �[1;38;5;8m2023-03-02 02:49:00 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge-guard�[0m BridgeHubWococo runtime spec version has changed from 9372 to 9371. Aborting relay
...
2023-03-02T07:31:05Z {pod="bridges-common-relay/bridges-common-relay-76bb7b87f7-qgzn9"} �[1;38;5;8m2023-03-02 07:31:05 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge-guard�[0m BridgeHubWococo runtime spec version has changed from 9371 to 9372. Aborting relay

Starting final relay (relay instance that is running now):

2023-03-02T07:33:50Z {pod="bridges-common-relay/bridges-common-relay-7f96994fb5-wgsvq"} + /home/user/substrate-relay relay-headers-and-messages bridge-hub-rococo-bridge-hub-wococo --bridge-hub-rococo-host rococo-bridge-hub-rpc.polkadot.io --bridge-hub-rococo-port 443 --bridge-hub-rococo-secure --bridge-hub-rococo-signer-file /secrets/rococo_signer --bridge-hub-rococo-transactions-mortality 32 --bridge-hub-wococo-host wococo-bridge-hub-rpc.polkadot.io --bridge-hub-wococo-port 443 --bridge-hub-wococo-secure --bridge-hub-wococo-signer-file /secrets/wococo_signer --bridge-hub-wococo-transactions-mortality 32 --lane 00000001 --rococo-headers-to-bridge-hub-wococo-signer-file /secrets/wococo_signer --rococo-host rococo-rpc.polkadot.io --rococo-parachains-to-bridge-hub-wococo-signer-file /secrets/wococo_signer --rococo-port 443 --rococo-secure --wococo-headers-to-bridge-hub-rococo-signer-file /secrets/rococo_signer --wococo-host wococo-rpc-node-0.parity-testnet.parity.io --wococo-parachains-to-bridge-hub-rococo-signer-file /secrets/rococo_signer --wococo-port 443 --wococo-secure --prometheus-host 0.0.0.0 --prometheus-port 9615

First final relay error (Rococo RPC node):

2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[38;5;12mTRACE�[0m �[38;5;8mbridge-metrics�[0m Refreshed process metrics: CPU=0.41300979256629944, memory=25878855680
2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mjsonrpsee_core::client::async_client�[0m [backend]: Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)
2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[38;5;12mTRACE�[0m �[38;5;8mbridge�[0m Rococo justification subscription stream has returned None. Stream needs to be restarted.
2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge�[0m [BridgeHubRococo-to-BridgeHubWococo-on-demand-parachain] Failed to read relay data from Rococo client: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)"))
2023-03-02T07:44:41Z {} [Rococo_to_BridgeHubWococo_Sync] �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge�[0m Finality sync loop iteration has failed with error: Source(RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)")))
2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[38;5;12mTRACE�[0m �[38;5;8mbridge�[0m [Wococo-to-BridgeHubRococo-on-demand-headers] Mandatory headers scan range: (4632536, "Ok(4632723)", "Ok(4632536)") -> Some((4632537, 4632723))
2023-03-02T07:44:41Z {} �[1;38;5;8m2023-03-02 07:44:41 +00�[0m �[38;5;12mTRACE�[0m �[38;5;8mbridge�[0m [Wococo-to-BridgeHubRococo-on-demand-headers] No mandatory Wococo headers in the range (4632537, 4632723)
2023-03-02T07:44:43Z {} �[1;38;5;8m2023-03-02 07:44:43 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge�[0m [Rococo-to-BridgeHubWococo-on-demand-headers] Failed to read best finalized source header from source: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)"))
2023-03-02T07:44:43Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-02 07:44:43 +00�[0m �[1;38;5;11mWARN�[0m �[38;5;8mbridge�[0m Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)"))

Rococo reconnect:

2023-03-02T07:44:51Z {} �[1;38;5;8m2023-03-02 07:44:51 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-02T07:44:51Z {} [Rococo_to_BridgeHubWococo_Sync] �[1;38;5;8m2023-03-02 07:44:51 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-02T07:44:51Z {} [Rococo_to_BridgeHubWococo_Sync] �[1;38;5;8m2023-03-02 07:44:51 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Restarting relay loop

And then reconnects again (by other relay - this isn't good, but not critical???):

2023-03-02T07:44:53Z {} �[1;38;5;8m2023-03-02 07:44:53 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-02T07:44:53Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-02 07:44:53 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-02T07:44:53Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-02 07:44:53 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Restarting relay loop

First WococoBridgeNode error and reconnect:

2023-03-02T07:53:15Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[38;5;12mTRACE�[0m �[38;5;8mbridge�[0m Refined weight of BridgeHubRococo->BridgeHubWococo message [0, 0, 0, 1]/13: at-source: Weight(ref_time: 0, proof_size: 0), at-target: Weight(ref_time: 0, proof_size: 0)
2023-03-02T07:53:15Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Received nonces from BridgeHubRococo::MessagesDelivery: SourceClientNonces { new_nonces: {13: MessageDetails { dispatch_weight: Weight { ref_time: 0, proof_size: 0 }, size: 56, reward: 0 }}, confirmed_nonce: Some(12) }
2023-03-02T07:53:15Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Received finalized nonces from BridgeHubWococo::MessagesDelivery: TargetClientNonces { latest_nonce: 12, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 11, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 1, messages_in_oldest_entry: 1, total_messages: 1, last_delivered_nonce: 12 } } }
2023-03-02T07:53:15Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Going to require BridgeHubRococo::MessagesDelivery header HeaderId(242635, 0x5b7087130b28af2238c6d9cd8b9b35c081260ff9ab14efbed3f6e47be91dc327) at BridgeHubWococo::MessagesDelivery
2023-03-02T07:53:15Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge�[0m Error asking for source headers at BridgeHubWococo::MessagesDelivery: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)")). Going to restart
2023-03-02T07:53:15Z {} [BridgeHubWococo_to_BridgeHubRococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:15 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Received finalized nonces from BridgeHubRococo::MessagesDelivery: TargetClientNonces { latest_nonce: 0, nonces_data: DeliveryRaceTargetNoncesData { confirmed_nonce: 0, unrewarded_relayers: UnrewardedRelayersState { unrewarded_relayer_entries: 0, messages_in_oldest_entry: 0, total_messages: 0, last_delivered_nonce: 0 } } }
...
2023-03-02T07:53:25Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:25 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubWococo node at wss://wococo-bridge-hub-rpc.polkadot.io:443
2023-03-02T07:53:25Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:25 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubRococo node at wss://rococo-bridge-hub-rpc.polkadot.io:443
2023-03-02T07:53:25Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-02 07:53:25 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Restarting relay loop 

After that ^^^ the relay always restarts when OnDemandParachainsRelay::prove_header is called:

2023-03-02 14:30:05	[BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] 2023-03-02 11:30:05 +00 DEBUG bridge Going to require BridgeHubRococo::MessagesDelivery header HeaderId(243709, 0x808dd741939ab18e31a2877519355fc8a829e45a3453c61000f4d945823a0574) at BridgeHubWococo::MessagesDelivery
2023-03-02 14:30:05	[BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] 2023-03-02 11:30:05 +00 ERROR bridge Error asking for source headers at BridgeHubWococo::MessagesDelivery: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)")). Going to restart

More specific, it fails in fn select_headers_to_prove(), because there's no line "[{}] Requested to prove {} head {:?}. Selected to prove {} head {:?} and {} head {:?}" in logs

@svyatonik
Copy link
Contributor Author

Apparently the fix isn't working

@svyatonik
Copy link
Contributor Author

Tonight log:

relay has been restarted
...
2023-03-03T01:58:48Z {} �[1;38;5;8m2023-03-03 01:58:48 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mjsonrpsee_core::client::async_client�[0m [backend]: Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)
2023-03-03T01:58:48Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-03 01:58:48 +00�[0m �[1;38;5;11mWARN�[0m �[38;5;8mbridge�[0m Rococo client has failed to return its sync status: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: i/o error: Connection reset by peer (os error 104)"))
2023-03-03T01:58:58Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-03 01:58:58 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-03T01:58:58Z {} [Rococo_to_BridgeHubWococo_Parachains_1013] �[1;38;5;8m2023-03-03 01:58:58 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Restarting relay loop
...
no errors
...
2023-03-03T06:43:50Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:43:50 +00�[0m �[1;38;5;9mERROR�[0m �[38;5;8mbridge�[0m Error asking for source headers at BridgeHubWococo::MessagesDelivery: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")). Going to restart
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubWococo node at wss://wococo-bridge-hub-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubRococo node at wss://rococo-bridge-hub-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubWococo node at wss://wococo-bridge-hub-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to Rococo node at wss://rococo-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;10mINFO�[0m �[38;5;8mbridge�[0m Connecting to BridgeHubWococo node at wss://wococo-bridge-hub-rpc.polkadot.io:443
2023-03-03T06:44:00Z {} [BridgeHubRococo_to_BridgeHubWococo_MessageLane_00000001] �[1;38;5;8m2023-03-03 06:44:00 +00�[0m �[38;5;14mDEBUG�[0m �[38;5;8mbridge�[0m Restarting relay loop
...
still the same errors

@svyatonik
Copy link
Contributor Author

svyatonik commented Mar 3, 2023

Have been able to reproduce it locally (I mean - to run relay locally, but connect to our regular nodes, with #1930 included) and it seems that the failure is for Rococo and the chain_getFinalizedHead call (the simplest possible call):

2023-03-03 10:43:15 +00 ERROR jsonrpsee_core::client::async_client [backend]: Networking or low-level protocol error: WebSocket connection error: connection closed
2023-03-03 10:43:17 +00 ERROR bridge [Rococo-to-BridgeHubWococo-on-demand-headers] Failed to read best finalized source header from source: FailedToReadBestFinalizedHeaderHash { chain: "Rococo", error: RpcError(RestartNeeded("Networking or low-level protocol error: WebSocket connection error: connection closed")) }

So it is not related to the requrest/response size

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment