[ws client] Failed to connect to sockaddr: 127.0.0.1:9944 with err: Rejected { status_code: 403 }

[emostov]

I am trying to use the ws client via substrate's remote-externalities. I can connect fine to wss://rpc.polkadot.io and if I add .handshake_url("/public-ws".into()) to the WsClientBuilder I can also connect to wss://polkadot.api.onfinality.io/public-ws.

But if I try connecting to a local node, ws://127.0.0.1:9944, I get the following error:

zeke substrate % RUST_LOG=debug cargo run --features=try-runtime --  try-runtime offchain-worker \
 --header-at 0x99007ac1e6cbff7efbacff7da6bb1b58480ba091c2f3eccc1648e5d22b92bc42 \
live ws://127.0.0.1:9944
    Running `target/debug/substrate try-runtime offchain-worker --header-at 0x99007ac1e6cbff7efbacff7da6bb1b58480ba091c2f3eccc1648e5d22b92bc42 live 'ws://127.0.0.1:9944'`
2021-05-27 11:03:53.843   INFO main remote-ext: initializing remote client to "ws://127.0.0.1:9944"    
2021-05-27 11:03:53.901  DEBUG main jsonrpsee_ws_client::transport: Failed to connect to sockaddr: 127.0.0.1:9944 with err: Rejected { status_code: 403 }    
Error: Input("failed to build ws client")

Exact error comes from here: https://github.com/paritytech/substrate/blob/fe9ced0c6048b45857e8806f8780a9a9a686421e/utils/frame/remote-externalities/src/lib.rs#L439-L443

I think ws://127.0.0.1:9944should be valid because I can use it to connect to the polkadot-js apps UI

[emostov]

FWIW nmap shows the port open, although not sure if it means much since I am running against localhost

zeke ~ % nmap -p T:9944 127.0.0.1
Starting Nmap 7.91 ( https://nmap.org ) at 2021-05-27 11:15 PDT
Nmap scan report for localhost (127.0.0.1)
Host is up (0.00017s latency).

PORT     STATE SERVICE
9944/tcp open  unknown

Nmap done: 1 IP address (1 host up) scanned in 0.07 seconds

[TarikGul]

although not sure if it means much since I am running against localhost

I good way to test that might be to have nmap within a cloud instance, and then targeting your ip from the outside.

[emostov]

Also bumped jsonrpsee to alpha.7 and have the same issue

I good way to test that might be to have nmap within a cloud instance, and then targeting your ip from the outside.

I don't want to expose it publicly though, just need a quick sanity check that the port is what I think it is

[TarikGul]

just need a quick sanity check that the port is what I think it is

Ahh I see what you are saying makes sense.

[emostov]

Here is a minimal repo to reproduce the issue: https://github.com/emostov/ws-client-test/blob/master/src/main.rs

Basically just start a polkadot node: polkadot % ./target/release/polkadot --chain=polkadot

And then within the repo cargo run

[emostov]

Closing

The issue was that I did not have the correct rpc-cors setting my polkadot node. Running the flag --rpc-cors=all solves the issue.

[dvdplm]

I took a look at this with @emostov and I think there's an actual issue here.

Running a minimal jsonrpsee example on localhost against a polkadot node I get this in my logs (started with: cargo run --release -- -lrpc=trace):

2021-05-27 21:48:54.387   INFO ThreadId(111) parity_ws::io: Accepted a new tcp connection from 127.0.0.1:54053.
2021-05-27 21:48:54.387   WARN ThreadId(111) jsonrpc_ws_server::session: Blocked connection to WebSockets server with untrusted host: Some("localhost")

When I run wscat -c 127.0.0.1:994 or wscat -c localhost:9944 I can connect, INFO ThreadId(111) parity_ws::io: Accepted a new tcp connection from 127.0.0.1:54243..

So I think we have some kind of bug. Possibly there's a bug in jsonrpc as well, but I think it's on our side.

The jsonrpsee logs:

➜  ws-debug git:(master) ✗ RUST_LOG=trace cargo run
   Compiling ws-debug v0.1.0 (/Users/aggron/dev/play/ws-debug)
    Finished dev [unoptimized + debuginfo] target(s) in 0.83s
     Running `target/debug/ws-debug`
Connecting to "ws://127.0.0.1:9944"
[2021-05-27T19:58:50Z TRACE polling::kqueue] new: kqueue_fd=10, read_stream=UnixStream { fd: 11, local: (unnamed), peer: (unnamed) }
[2021-05-27T19:58:50Z TRACE polling::kqueue] add: kqueue_fd=10, fd=9, ev=Event { key: 0, readable: false, writable: false }
[2021-05-27T19:58:50Z TRACE async_io::driver] main_loop: waiting on I/O
[2021-05-27T19:58:50Z TRACE polling::kqueue] add: kqueue_fd=10, fd=9, ev=Event { key: 0, readable: false, writable: true }
[2021-05-27T19:58:50Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2021-05-27T19:58:50Z TRACE polling] Poller::wait(_, None)
[2021-05-27T19:58:50Z TRACE polling::kqueue] wait: kqueue_fd=10, timeout=None
[2021-05-27T19:58:50Z TRACE polling] Poller::notify()
[2021-05-27T19:58:50Z TRACE polling::kqueue] new events: kqueue_fd=10, res=1
[2021-05-27T19:58:50Z TRACE polling::kqueue] notify: kqueue_fd=10
[2021-05-27T19:58:50Z TRACE async_io::reactor] react: 1 ready wakers
[2021-05-27T19:58:50Z TRACE async_io::driver] main_loop: waiting on I/O
[2021-05-27T19:58:50Z TRACE async_io::reactor] writable: fd=9
[2021-05-27T19:58:50Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2021-05-27T19:58:50Z TRACE polling] Poller::wait(_, Some(9.999904271s))
[2021-05-27T19:58:50Z TRACE polling::kqueue] wait: kqueue_fd=10, timeout=Some(9.999904271s)
[2021-05-27T19:58:50Z TRACE polling::kqueue] new events: kqueue_fd=10, res=1
[2021-05-27T19:58:50Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2021-05-27T19:58:50Z TRACE async_io::reactor] react: 0 ready wakers
[2021-05-27T19:58:50Z TRACE async_io::driver] main_loop: waiting on I/O
[2021-05-27T19:58:50Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2021-05-27T19:58:50Z TRACE polling] Poller::wait(_, None)
[2021-05-27T19:58:50Z TRACE polling::kqueue] wait: kqueue_fd=10, timeout=None
[2021-05-27T19:58:50Z TRACE polling::kqueue] add: kqueue_fd=10, fd=9, ev=Event { key: 0, readable: true, writable: false }
[2021-05-27T19:58:50Z TRACE polling::kqueue] new events: kqueue_fd=10, res=1
[2021-05-27T19:58:50Z TRACE async_io::reactor] react: 1 ready wakers
[2021-05-27T19:58:50Z TRACE async_io::driver] main_loop: waiting on I/O
[2021-05-27T19:58:50Z TRACE async_io::reactor] process_timers: 0 ready wakers
[2021-05-27T19:58:50Z TRACE soketto] read 112 bytes
[2021-05-27T19:58:50Z TRACE polling] Poller::wait(_, None)
[2021-05-27T19:58:50Z TRACE polling::kqueue] wait: kqueue_fd=10, timeout=None
[2021-05-27T19:58:50Z TRACE polling::kqueue] add: kqueue_fd=10, fd=9, ev=Event { key: 0, readable: false, writable: false }
[2021-05-27T19:58:50Z DEBUG jsonrpsee_ws_client::transport] Failed to connect to sockaddr: 127.0.0.1:9944 with err: Rejected { status_code: 403 }
Error: Networking or low-level protocol error: Connection rejected with status code: 403

Caused by:
    Connection rejected with status code: 403

[dvdplm]

I think I found what is causing this: https://github.com/paritytech/soketto/blob/38f5254ad230f2d16ea0d087be527abb21321500/src/handshake/client.rs#L143-L144

It seems like polkadot (i.e. jsonrpc) does not accept connections when the handshake contains the Host header, regardless of the value (localhost in this case). If I comment out those lines in soketto my example code works.

To verify, I also used wscat.

This fails to connect to my node: wscat -c localhost:9944 -H "Host: localhost" while wscat -c localhost:9944 works fine.

Vice versa, connecting from jsonrpsee to wscat -l localhost:9945 works fine.

So this is a jsonrpc bug after all?

[niklasad1]

So this is a jsonrpc bug after all?

No, I don't think so.

wscat sends the following:

GET / HTTP/1.1
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: y3jtiWmJr2LXPR1Nnj9JJQ==
Connection: Upgrade
Upgrade: websocket
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits
Host: 127.0.0.1:9944

jsonrpsee sends:

GET / HTTP/1.1
Host: 127.0.0.1
Upgrade: websocket
Connection: Upgrade
Sec-WebSocket-Key: 3VL80HaYQZgz3GnvMwMjlA==
Sec-WebSocket-Version: 13

EDIT:
https://developer.mozilla.org/en-US/docs/Web/HTTP/Headers/Host

So it's wrong, thanks for catching this @emostov & @dvdplm

[dvdplm]

So it's wrong, thanks for catching this @emostov & @dvdplm

right, I just read through the rfcs and found this.