Skip to content
This repository has been archived by the owner on Oct 19, 2024. It is now read-only.

Subscriptions stop working after websocket reconnect #2418

Closed
gbrew opened this issue May 15, 2023 · 1 comment
Closed

Subscriptions stop working after websocket reconnect #2418

gbrew opened this issue May 15, 2023 · 1 comment
Labels
bug Something isn't working

Comments

@gbrew
Copy link
Contributor

gbrew commented May 15, 2023

Version
All ethers crates are v2.0.4

Platform
Mac M1, various linux machines

Description
When subscribing to events with a websocket provider, the websocket reconnect is working, but subscription events silently stop arriving after the reconnect.

I've reproduced this with verbose tracing, and see the following:

2023-05-13T05:26:12.971430Z DEBUG handle_notification{server_id=219955609548486610141028279121231813592}: ethers_providers::rpc::transports::ws::manager: Forwarding notification to listener id=0 got tx 0xd9946764e11eae15c0e8fbbbbed92b43f32e24fa2881039a35df1e0d6ffd98b3 2023-05-13T05:26:29.564366Z DEBUG jsonrpsee_client_transport::ws: Send ping 2023-05-13T05:27:02.546881Z ERROR ethers_providers::rpc::transports::ws::backend: Error response from WS err=WebSocket protocol error: Connection reset without closing handshake 2023-05-13T05:27:02.547646Z INFO ethers_providers::rpc::transports::ws::manager: Reconnecting to backend remaining=18446744073709551614 url="wss://searchers.mevblocker.io:443" 2023-05-13T05:27:03.843435Z DEBUG ethers_providers::rpc::transports::ws::manager: Draining old backend to_handle channel 2023-05-13T05:27:03.843579Z DEBUG ethers_providers::rpc::transports::ws::manager: Re-starting active subscriptions count=1 2023-05-13T05:27:03.843708Z DEBUG ethers_providers::rpc::transports::ws::manager: Re-issuing pending requests count=0 2023-05-13T05:27:03.843754Z INFO ethers_providers::rpc::transports::ws::manager: Re-connection complete subs=1 reqs=0 2023-05-13T05:27:04.061842Z TRACE ethers_providers::rpc::transports::ws::backend: Received message text="{\"jsonrpc\": \"2.0\", \"id\": 0, \"result\": \"0xfedd937ffcb30b8a133ea5a6ae1b8241\"}" 2023-05-13T05:27:04.062045Z TRACE ethers_providers::rpc::transports::ws::backend: Deserialized message item=Req success. ID: 0 2023-05-13T05:27:04.062208Z TRACE ethers_providers::rpc::transports::ws::backend: Received message text="{\"jsonrpc\": \"2.0\", \"method\": \"eth_subscription\", \"params\": {\"subscription\": \"0xfedd937ffcb30b8a133ea5a6ae1b8241\", \"result\": {\"chainId\": \"0x1\", \"to\": \"0xef1c6e67703c7bd7107eed8303fbe6ec2554bf6b\", \"value\": \"0xde0b6b3a7640000\", \"data\": \"0x3593564c000000000000000000000000000000000000000000000000000000000000006000000000000000000000000000000000000000000000000000000000000000a000000000000000000000000000000000000000000000000000000000645f219b00000000000000000000000000000000000000000000000000000000000000020b080000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002000000000000000000000000000000000000000000000000000000000000004000000000000000000000000000000000000000000000000000000000000000a0000000000000000000000000000000000000000000000000000000000000004000000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000000000000000000de0b6b3a7640000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000de0b6b3a76400000000000000000000000000000000000000000000aa1de67a5b144aa868aa936f00000000000000000000000000000000000000000000000000000000000000a000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002000000000000000000000000c02aaa39b223fe8d0a0e5c4f27ead9083c756cc2000000000000000000000000d8e2d95c8614f28169757cd6445a71c291dec5bf\", \"accessList\": [], \"nonce\": \"0x888\", \"maxPriorityFeePerGas\": \"0x0\", \"maxFeePerGas\": \"0xd26bc26f9\", \"gas\": \"0x31e2a\", \"type\": \"0x2\", \"hash\": \"0xaf4b429e5739a4422cb801482fa3e8f8463a83b10f498286b3148db75fb07106\", \"from\": \"0x0ecc67316c8027e66654ddafaacd25fb5c5f4df9\"}}}" 2023-05-13T05:27:04.062478Z TRACE ethers_providers::rpc::transports::ws::backend: Deserialized message item=Notification for sub: 338774400189499879420354125175499489857 2023-05-13T05:27:04.063081Z TRACE req_success{id=0}: ethers_providers::rpc::transports::ws::manager: Success response received result="0xfedd937ffcb30b8a133ea5a6ae1b8241" 2023-05-13T05:27:04.063239Z TRACE req_success{id=0}: ethers_providers::rpc::transports::ws::manager: No InFlight found 2023-05-13T05:27:04.063569Z DEBUG handle_notification{server_id=338774400189499879420354125175499489857}: ethers_providers::rpc::transports::ws::manager: No aliased subscription found server_id="0xfedd937ffcb30b8a133ea5a6ae1b8241"

It appears that the issue is that the code which handles resubscription re-sends the subscription request properly, but there is no inflight request for it, so when the response arrives, it gets "No InFlight found", and then does not update the subscription for the new server-side subscription ID.

I've tested a fix for this, and will put up a PR for it shortly.

@gbrew gbrew added the bug Something isn't working label May 15, 2023
@stuffy-idler
Copy link

@gbrew @DaniPopes this issue should be closed since it was fixed in #2419

Thanks @gbrew for issue and fix!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants