Originally posted by **snowmead** December 19, 2023
Based on this subxt [`LightClient`]() example, the gossip protocol does not seem to be available.
```
2023-12-19T15:24:08.272992Z DEBUG network: Gossip(local_testnet, 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) => OpenFailed(error=Substream(Substream(ProtocolNotAvailable)))
```
My configuration is based on the raw chain spec built from the template node I am running and overriding the bootnodes to connect to the locally running node.
The `await` on the `build()` function hangs and loops with the same logs shown below.
```rust
let chain_spec = match chain {
SupportedChains::Local | SupportedChains::Compose => {
include_bytes!("metadata/local/local.scale");
include_str!("metadata/local/customSpecRaw.json")
},
};
let api = LightClient::::builder()
.bootnodes(chain.bootnodes())
.max_pending_requests(NonZeroU32::MAX)
.build(chain_spec)
.await
.expect("Failed to create light client");
```
Lightclient logs:
```
2023-12-19T15:24:08.158024Z INFO libp2p_swarm: local_peer_id=12D3KooWM97vjfGBVS139zPB737Lf9gBQWsV1jg3v7dr5QQYDwFb
2023-12-19T15:24:08.158147Z DEBUG libp2p_tcp: listening on address address=0.0.0.0:33411
2023-12-19T15:24:08.158230Z DEBUG netlink_proto::handle: handle: forwarding new request to connection
2023-12-19T15:24:08.262706Z INFO smoldot: Chain initialization complete for local_testnet. Name: "Local Testnet". Genesis hash: 0x957e…5c38. Chain specification starting at: 0x957e…5c38 (#0)
2023-12-19T15:24:08.262921Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2023-12-19T15:24:08.263020Z DEBUG json-rpc-local_testnet: JSON-RPC => {"jsonrpc":"2.0","id":"1", "method":"chain_getFinalizedHead","params":[]}
2023-12-19T15:24:08.263130Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2023-12-19T15:24:08.263224Z WARN json-rpc-local_testnet: The JSON-RPC client has just called a JSON-RPC function from the legacy JSON-RPC API (chain_getFinalizedHead). Legacy JSON-RPC functions have loose semantics and cannot be properly implemented on a light client. You are encouraged to use the new JSON-RPC API instead. The legacy JSON-RPC API functions will be deprecated and removed in the distant future.
2023-12-19T15:24:08.263257Z DEBUG runtime-local_testnet: Worker <= Reset(finalized_block: 0x957e…5c38)
2023-12-19T15:24:08.263346Z DEBUG network: Connections(12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) <= StartConnecting(remote_addr=/ip4/127.0.0.1/tcp/30333, local_peer_id=12D3KooWNTPGrD9hc9CBoYbbueaCyUTcRTP4T2ZV3KHAJmTXD7u1)
2023-12-19T15:24:08.271649Z DEBUG network: Connections(12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp, /ip4/127.0.0.1/tcp/30333) => HandshakeFinished
2023-12-19T15:24:08.271748Z DEBUG network: Gossip(local_testnet, 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) <= Open
2023-12-19T15:24:08.272992Z DEBUG network: Gossip(local_testnet, 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) => OpenFailed(error=Substream(Substream(ProtocolNotAvailable)))
2023-12-19T15:24:08.273043Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (ban_duration=15s)
2023-12-19T15:24:08.773370Z DEBUG network: Connections(12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) => IdentifyRequest
2023-12-19T15:24:13.263114Z DEBUG network: Discovery(local_testnet) => NoPeer
2023-12-19T15:24:18.263177Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2023-12-19T15:24:23.263347Z DEBUG network: Discovery(local_testnet) => NoPeer
2023-12-19T15:24:23.273360Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2023-12-19T15:24:23.273483Z DEBUG network: Gossip(local_testnet, 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) <= Open
2023-12-19T15:24:23.274518Z DEBUG network: Gossip(local_testnet, 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) => OpenFailed(error=Substream(Substream(ProtocolNotAvailable)))
2023-12-19T15:24:23.274555Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (ban_duration=15s)
2023-12-19T15:24:28.263383Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
```
And I have this warning message regarding the RPC api used to query `chain_getFinalizedHead`.
The legacy RPC call is being utilized instead of the new one. Is there some flag or configuration I need to specify to fix this, or is it simply not implemented in the library yet?
```
2023-12-19T15:24:08.263224Z WARN json-rpc-local_testnet: The JSON-RPC client has just called a JSON-RPC function from the legacy JSON-RPC API (chain_getFinalizedHead). Legacy JSON-RPC functions have loose semantics and cannot be properly implemented on a light client. You are encouraged to use the new JSON-RPC API instead. The legacy JSON-RPC API functions will be deprecated and removed in the distant future.
2023-12-19T15:24:08.263257Z DEBUG runtime-local_testnet: Worker <= Reset(finalized_block: 0x957e…5c38)
```
Based on this subxt LightClient example, the gossip protocol does not seem to be available.
I don't know but can you provide some steps how to reproduce that? Could be something in the chain spec that causes that because the chain spec is passed/handled by smoldot and subxt isn't managing that directly.... when @lexnv is back he can probably take a look as well
And I have this warning message regarding the RPC api used to query chain_getFinalizedHead.
The legacy RPC call is being utilized instead of the new one. Is there some flag or configuration I need to specify to fix this, or is it simply not implemented in the library yet?
We should fix that and I think the reason is that the new RPC spec was implemented after the LightClient was initially added but thanks for raising the issue. @lexnv any other reasons for that?
We should fix that and I think the reason is that the new RPC spec was implemented after the LightClient was initially added but thanks for raising the issue. @lexnv any other reasons for that?
Just to add; Subxt has two "backends" which determine the RPC methods that will be called. The "legacy backend" is the default one, and calls the "legacy" (ie old) RPC methods. Smoldot emits the warnings you see when such legacy methods are used, because they are not properly specified.
Subxt also supports the "new" chainHead RPC methods which will eventually replace these and are properly specified (see https://paritytech.github.io/json-rpc-interface-spec). These are not the default yet though becaus they are still a WIP and aren't themselves stabilised yet, so they may break at any time. When they are stabilised, Subxt will use them by default and the warnings will go away.
The await on the build() function hangs and loops with the same logs shown below.
It appears from the logs that the chain_getFinalizedHead RPC call is made (the first call we await on when you .build(chain_spec)), but no response is seen coming back. Indeed the OpenFailed and then NoPeer messages are suspicious. It might be that the Smoldot update in eg #1337 will help. it might also be that the bootnode config has some issue and isn't pointing to the correct locally running node; @snowmead I wonder whether things seem to work (or at least make more progress) when you leave the bootnodes list alone (ie so it can connect to the default bootnodes)?
It appears from the logs that the chain_getFinalizedHead RPC call is made (the first call we await on when you .build(chain_spec)), but no response is seen coming back. Indeed the OpenFailed and then NoPeer messages are suspicious. It might be that the Smoldot update in eg https://github.com/paritytech/subxt/pull/1337 will help.
After cloning subxt which runs with smoldot = 0.15, it reaches some new error. It still hangs and can't complete the build step.
2024-01-03T20:56:57.886815Z INFO libp2p_swarm: local_peer_id=12D3KooWHUCJaYZYUxn4bzaYqyxsDxK8cwJpeXXDKACppPRH84uP
2024-01-03T20:56:57.887334Z DEBUG libp2p_tcp: listening on address address=*******:33411
2024-01-03T20:56:58.048946Z INFO smoldot: Chain initialization complete for local_testnet. Name: "Local Testnet". Genesis hash: 0x957e…5c38. Chain specification starting at: 0x957e…5c38 (#0)
2024-01-03T20:56:58.049813Z DEBUG network: Chains <= AddChain(id=local_testnet)
2024-01-03T20:56:58.050881Z DEBUG runtime-local_testnet: Worker <= Reset(finalized_block: 0x957e…5c38)
2024-01-03T20:56:58.051193Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2024-01-03T20:56:58.051395Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2024-01-03T20:56:58.051612Z DEBUG runtime-local_testnet: Worker <= FailedDownload(blocks=[0x957e…5c38], error=StorageQuery(StorageQueryError { errors: [] }))
2024-01-03T20:56:58.051741Z DEBUG json-rpc-local_testnet: JSON-RPC => {"jsonrpc":"2.0","id":"1", "method":"chain_getFinalizedHead","params":[]}
2024-01-03T20:56:58.051999Z WARN json-rpc-local_testnet: The JSON-RPC client has just called a JSON-RPC function from the legacy JSON-RPC API (chain_getFinalizedHead). Legacy JSON-RPC functions have loose semantics and cannot be properly implemented on a light client. You are encouraged to use the new JSON-RPC API <https://github.com/paritytech/json-rpc-interface-spec/> instead. The legacy JSON-RPC API functions will be deprecated and removed in the distant future.
2024-01-03T20:56:58.052113Z DEBUG network: Connections(12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp) <= StartConnecting(remote_addr=/ip4/*********/tcp/30333, local_peer_id=12D3KooWE959kG47tN61JtDnedcvxfwgW4RUA3HMiSGXtNLtM9Vt)
2024-01-03T20:56:58.058095Z DEBUG network: Connections(12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp, /ip4/*********/tcp/30333) => HandshakePeerIdMismatch(actual=12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G)
2024-01-03T20:56:58.058241Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (reason=no-address, ban-duration=10s)
2024-01-03T20:56:58.565000Z DEBUG network: Connections(12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G) => IdentifyRequest
2024-01-03T20:57:00.061535Z DEBUG network: Connections(12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G, /ip4/*********/tcp/30333) => Ping(2.380625ms)
2024-01-03T20:57:03.049160Z DEBUG network: Discovery(local_testnet) => NoPeer
2024-01-03T20:57:08.050025Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:57:08.051998Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2024-01-03T20:57:08.052221Z DEBUG runtime-local_testnet: Worker <= FailedDownload(blocks=[0x957e…5c38], error=StorageQuery(StorageQueryError { errors: [] }))
2024-01-03T20:57:08.059098Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2024-01-03T20:57:08.059195Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (reason=no-address, ban-duration=10s)
2024-01-03T20:57:13.050860Z DEBUG network: Discovery(local_testnet) => NoPeer
2024-01-03T20:57:18.051226Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:57:18.056190Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2024-01-03T20:57:18.056460Z DEBUG runtime-local_testnet: Worker <= FailedDownload(blocks=[0x957e…5c38], error=StorageQuery(StorageQueryError { errors: [] }))
2024-01-03T20:57:18.059642Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2024-01-03T20:57:18.059742Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (reason=no-address, ban-duration=10s)
2024-01-03T20:57:20.066570Z DEBUG network: Connections(12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G, /ip4/*********/tcp/30333) => Ping(6.159416ms)
2024-01-03T20:57:28.052460Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:57:28.056814Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2024-01-03T20:57:28.056985Z DEBUG runtime-local_testnet: Worker <= FailedDownload(blocks=[0x957e…5c38], error=StorageQuery(StorageQueryError { errors: [] }))
2024-01-03T20:57:28.060207Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp
2024-01-03T20:57:28.060369Z DEBUG network: Slots(local_testnet) ∌ 12D3KooWEyoppNCUx8Yx66oV9fJnriXwCcXwDDUA2kj6vnc6iDEp (reason=no-address, ban-duration=10s)
2024-01-03T20:57:33.051963Z DEBUG network: Discovery(local_testnet) => NoPeer
I wonder whether things seem to work (or at least make more progress) when you leave the bootnodes list alone (ie so it can connect to the default bootnodes)?
I also tried removing the bootnodes() config and this did not help since it will not try to connect to the local running node.
2024-01-03T20:45:09.423674Z INFO libp2p_swarm: local_peer_id=12D3KooWK1U42tF4FjhsVJ6ymzw4YgFNSknHxwXjHG4ACkE7SB5L
2024-01-03T20:45:09.424220Z DEBUG libp2p_tcp: listening on address address=*******:33411
2024-01-03T20:45:09.581845Z INFO smoldot: Chain initialization complete for local_testnet. Name: "Local Testnet". Genesis hash: 0x957e…5c38. Chain specification starting at: 0x957e…5c38 (#0)
2024-01-03T20:45:09.583041Z DEBUG runtime-local_testnet: Worker => NewDownload(block=0x957e…5c38)
2024-01-03T20:45:09.583348Z DEBUG runtime-local_testnet: Worker <= Reset(finalized_block: 0x957e…5c38)
2024-01-03T20:45:09.583392Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ
2024-01-03T20:45:09.583616Z DEBUG json-rpc-local_testnet: JSON-RPC => {"jsonrpc":"2.0","id":"1", "method":"chain_getFinalizedHead","params":[]}
2024-01-03T20:45:09.583904Z WARN json-rpc-local_testnet: The JSON-RPC client has just called a JSON-RPC function from the legacy JSON-RPC API (chain_getFinalizedHead). Legacy JSON-RPC functions have loose semantics and cannot be properly implemented on a light client. You are encouraged to use the new JSON-RPC API <https://github.com/paritytech/json-rpc-interface-spec/> instead. The legacy JSON-RPC API functions will be deprecated and removed in the distant future.
2024-01-03T20:45:09.584018Z DEBUG network: Connections(12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ) <= StartConnecting(remote_addr=/ip4/*********/tcp/30333, local_peer_id=12D3KooWGiaCsJKAS4wRPJ7oBMusBsaUsVAFjHnJhQGoUYVxEGya)
2024-01-03T20:45:09.596835Z DEBUG network: Connections(12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ, /ip4/*********/tcp/30333) => HandshakePeerIdMismatch(actual=12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G)
2024-01-03T20:45:10.103379Z DEBUG network: Connections(12D3KooWDbCHMVTFaq6aGMNYK5GuzErCtNStNoW2hH8iHYYt7R5G) => IdentifyRequest
2024-01-03T20:45:14.582834Z DEBUG network: Discovery(local_testnet) => NoPeer
2024-01-03T20:45:19.583161Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:45:19.598317Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ
2024-01-03T20:45:24.585242Z DEBUG network: Discovery(local_testnet) => NoPeer
2024-01-03T20:45:29.584506Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:45:29.599883Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ
2024-01-03T20:45:39.585799Z WARN sync-service-local_testnet: GrandPa warp sync idle at block #0 (0x0x957e…5c38)
2024-01-03T20:45:39.601297Z DEBUG network: Slots(local_testnet) ∋ 12D3KooWM53NaHyeVgRPoS7iN8HsE9sJPF1Sg8poCYWrV9Qf5ZhZ
Hello! I've tried to use the new version and this problem persists.
I am generating the chain spec as @snowmead mentioned. The code is the example with just the chain spec changed.
The parachain is a forked substrate-node-template example (which uses polkadot-v1.0.0) with minor changes.
Logs are the same as here.
Discussed in https://github.com/paritytech/subxt/discussions/1325
I don't know but can you provide some steps how to reproduce that? Could be something in the chain spec that causes that because the chain spec is passed/handled by smoldot and subxt isn't managing that directly.... when @lexnv is back he can probably take a look as well
It's implemented by the subxt but it's not used when initializing the client because LightClientBuilder::build calls from_rpc_client which using the legacy RPC
We should fix that and I think the reason is that the new RPC spec was implemented after the LightClient was initially added but thanks for raising the issue. @lexnv any other reasons for that?
I generate the chainspec using the following commands from a substrate node template:
The rest is described above. Nothing special added to the bootstrapping process.
Just to add; Subxt has two "backends" which determine the RPC methods that will be called. The "legacy backend" is the default one, and calls the "legacy" (ie old) RPC methods. Smoldot emits the warnings you see when such legacy methods are used, because they are not properly specified.
Subxt also supports the "new" chainHead RPC methods which will eventually replace these and are properly specified (see https://paritytech.github.io/json-rpc-interface-spec). These are not the default yet though becaus they are still a WIP and aren't themselves stabilised yet, so they may break at any time. When they are stabilised, Subxt will use them by default and the warnings will go away.
It appears from the logs that the
chain_getFinalizedHead
RPC call is made (the first call we await on when you.build(chain_spec)
), but no response is seen coming back. Indeed theOpenFailed
and thenNoPeer
messages are suspicious. It might be that the Smoldot update in eg #1337 will help. it might also be that the bootnode config has some issue and isn't pointing to the correct locally running node; @snowmead I wonder whether things seem to work (or at least make more progress) when you leave the bootnodes list alone (ie so it can connect to the default bootnodes)?We should also double check that we can configure a light client to point to a dev node and it works ok still (eg start with this example https://github.com/paritytech/subxt/blob/master/subxt/examples/light_client_tx_basic.rs and if that works as-is, we could try to export the chainspec as above and does that still work?)
@jsdw @niklasad1
After cloning
subxt
which runs withsmoldot = 0.15
, it reaches some new error. It still hangs and can't complete thebuild
step.I also tried removing the
bootnodes()
config and this did not help since it will not try to connect to the local running node.From looking at the logs, the issue seems to be that the lightclient is stuck during warp sync:
This is most likely related to my investigation work https://github.com/paritytech/subxt/pull/1355 and https://github.com/paritytech/subxt/pull/1354 and the following smoldot issue https://github.com/smol-dot/smoldot/issues/1562.
To work around the issue, I would try cherry-picking this patch: https://github.com/paritytech/subxt/pull/1355/commits/d4da6281d697284d9b290c366bb926995f58f7a7; although a proper fix in smoldot should handle this for production use-case
After applying this patch https://github.com/paritytech/subxt/commit/d4da6281d697284d9b290c366bb926995f58f7a7, I get this error still when it attempts to download blocks:
FailedDownload(blocks=[0xac28…7046], error=StorageQuery(StorageQueryError { errors: [] }))
Code snippet for bootstrapping lightclient:
Hey, thanks for letting us know.
Could you retry running with the latest origin/master? We have included a series of fixes, out of which https://github.com/paritytech/subxt/pull/1372 should handle this.
Hello! I've tried to use the new version and this problem persists.
I am generating the chain spec as @snowmead mentioned. The code is the example with just the chain spec changed. The parachain is a forked substrate-node-template example (which uses
polkadot-v1.0.0
) with minor changes. Logs are the same as here.