Expected subscription, but received an id response instead

[brenzi]

[2023-07-17T12:15:31Z WARN substrate_api_client::rpc::ws_client] Expected subscription, but received an id response instead: Object {"id": String("1"), "jsonrpc": String("2.0"), "result": String("5mV2Ue1jpPJKhTBp")}

I guess this has to do with recent update of behavior of the spi-client.
This happens when we do
submit_and_watch_extrinsic_until

using api client: polkadot-v0.9.42-tag-v0.10.0#686b7ef0aa8da255d3864a3fc703e32193813700
node is based on: polkadot-v0.9.42#569aae5341ea0c1d10426fa1ec13a36c0b64393b

it looks like the consequence of this warning is that the return value is "extrinsic failed" although it succeeded

[brenzi]

same warning already occurred on a previous dep:
https://github.com/scs/substrate-api-client.git?branch=polkadot-v0.9.39#d872c2ca4328a30222e4d470c8fc4921abad9f34
where the node was based on
https://github.com/paritytech/substrate.git?branch=polkadot-v0.9.39#1837f423b494254e1d27834b1c9da34b2c0c2375

[brenzi]

this should be an error, not a warning, because it seems to subsequontly cause ExtrinsicNotFound

• the extrinsic succeeds
• the returned block hash is wrong (is a later block than the one where the extrinsic got included)
• therefore ExtrinsicNotFound in that wrong block

not sure if related: #621

[brenzi]

steps to reproduce:

run integritee-node 1.0.36 (polkadot-0.9.42 deps)

wget https://github.com/integritee-network/integritee-node/releases/download/1.0.36/integritee-node-dev
chmod +x integritee-node-dev
./integritee-node-dev --dev 

run substrate api client example:

git checkout polkadot-v0.9.42-tag-v0.10.0
export RUST_LOG=warn
cargo run -p ac-examples --example transfer_with_ws_client

this will hang. a warning will be issued (because runtimes don't match), but actually it should terminate with an error. - but that's not our real issue

let's build against integritee-node-runtime:

diff --git a/examples/Cargo.toml b/examples/Cargo.toml
index dc4e87b..d27c48f 100644
--- a/examples/Cargo.toml
+++ b/examples/Cargo.toml
@@ -15,7 +15,7 @@ wabt = "0.10.0"
 # Substrate dependencies
 frame-support = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
 frame-system = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
-kitchensink-runtime = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
+#kitchensink-runtime = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
 pallet-balances = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
 pallet-identity = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
 pallet-staking = { git = "https://github.com/paritytech/substrate.git", branch = "polkadot-v0.9.42" }
@@ -26,3 +26,5 @@ sp-version = { git = "https://github.com/paritytech/substrate.git", branch = "po
 
 # local deps
 substrate-api-client = { path = "..", features = ["tungstenite-client", "ws-client", "staking-xt"] }
+
+my-runtime = { package = "integritee-node-runtime", git = "https://github.com/integritee-network/integritee-node.git", branch = "polkadot-v0.9.42" }

and

diff --git a/examples/examples/transfer_with_ws_client.rs b/examples/examples/transfer_with_ws_client.rs
index e3c86bf..caf8875 100755
--- a/examples/examples/transfer_with_ws_client.rs
+++ b/examples/examples/transfer_with_ws_client.rs
@@ -15,16 +15,14 @@
 
 //! Very simple example that shows how to use a predefined extrinsic from the extrinsic module.
 
-use kitchensink_runtime::{Runtime, Signature};
+//use kitchensink_runtime::{Runtime, Signature};
+use my_runtime::{Runtime, Signature};
 use sp_core::{
        crypto::{Pair, Ss58Codec},
        sr25519,
 };
 use sp_runtime::MultiAddress;
-use substrate_api_client::{
-       extrinsic::BalancesExtrinsics, rpc::WsRpcClient, Api, AssetTipExtrinsicParams, ExtrinsicSigner,
-       GetAccountInformation, SubmitAndWatch, XtStatus,
-};
+use substrate_api_client::{extrinsic::BalancesExtrinsics, rpc::WsRpcClient, Api, AssetTipExtrinsicParams, ExtrinsicSigner, GetAccountInformation, SubmitAndWatch, XtStatus, PlainTipExtrinsicParams};
 
 fn main() {
        env_logger::init();
@@ -39,7 +37,7 @@ fn main() {
 
        // Initialize api and set the signer (sender) that is used to sign the extrinsics.
        let client = WsRpcClient::with_default_url();
-       let mut api = Api::<_, _, AssetTipExtrinsicParams<Runtime>, Runtime>::new(client).unwrap();
+       let mut api = Api::<_, _, PlainTipExtrinsicParams<Runtime>, Runtime>::new(client).unwrap();
        api.set_signer(ExtrinsicSigner::<_, Signature, Runtime>::new(alice.clone()));
 
        // Retrieve bobs current balance.

then, the result is:

signer account: 5GrwvaEF5zXb26Fz9rcQpDWS57CtERHpNehXCPcNoHGKutQY
[+] Bob's Free Balance is is 1000000000000000

Sending an extrinsic from Alice (Key = 5GrwvaEF5zXb26Fz9rcQpDWS57CtERHpNehXCPcNoHGKutQY),

to Bob (Key = 5FHneW46xGXgs5mUiveU4sbTyGBzmstUspZC92UhjJM694ty)

[+] Composed extrinsic: UncheckedExtrinsic(Some((MultiAddress::Id(d43593c715fdd31c61141abd04a99fd6822c8558854ccde39a5684e7a56da27d (5GrwvaEF...)), GenericSignedExtra { era: Era::Immortal, nonce: 0, tip: PlainTip { tip: 0 } })), ([10, 0], MultiAddress::Id(8eaf04151687736326c9fea17e25fc5287613693c912909cb226aa4794f26a48 (5FHneW46...)), 1000000000000))

[2023-07-20T12:40:04Z WARN  substrate_api_client::rpc::ws_client] Expected subscription, but received an id response instead: Object {"id": String("1"), "jsonrpc": String("2.0"), "result": String("q5TGkL98VIMoB5ME")}
[+] Extrinsic got included. Hash: 0x51c4dba3f1518150685e48041c17d211c78d58a4148734f94fe448b05ba4f757

[+] Bob's Free Balance is now 1001000000000000

in this case, however, the reported block hash is correct. still, what is the warning about?

[masapr]

Hi @brenzi
Thanks a lot for the example. I could reproduce it (both the hanging and the actual produced warning). If it's ok, @haerdib can look at it, beginning of next week.

[brenzi]

it was good reproducing this issue with the basic api-client example. This actually showed me that our problem seems to be rooted elsewhere. Why?

• the returned hash is correct and the extrinsic success is correctly handled
• in our case, the client thinks that the extrinsic failed although it succeeded.

Therefore, we may need to investigate further. While this warning is confusing and should be tackled IMO, getting rid of it will very likely not resolve our issue.

[brenzi]

our real issue is #624

[haerdib]

Summarizing Issues:

• Warning instead of an error if Expected subscription, but received an id response instead. This will be investigated in a separate issue: Fix Warning Expected subscription, but received an id response instead #626.
• Warning [2023-07-20T12:40:04Z WARN substrate_api_client::rpc::ws_client] Expected subscription, but received an id response instead: Object {"id": String("1"), "jsonrpc": String("2.0"), "result": String("q5TGkL98VIMoB5ME")} even though example runs through successfully. Also investigated in Fix Warning Expected subscription, but received an id response instead #626
• Failed extrinsic, even though it suceeded. Investigated in got Error ExtrinsicNotFound although extrinsic succeeded (for extrinsic with zero-padding at the end) #624

[haerdib]

Closing this for now. To my understanding, all issues are already tracked in other issues. Please reopen if that's not the case.