pusher-websocket-swift: Pusher fail to reconnect properly when coming back in foreground

Steps to reproduce

  • Go in background
  • Wait a few seconds
  • Go back in your app

Expected behavior

Pusher reconnect and subscribe to channels

Actual behavior

Connection fail with message “Invalid signature: Expected HMAC SHA256 hex digest” and no channel is subscribed

We did some digging. It seem that when coming back in foreground Pusher lib has hard time connecting and make many back and forth between disconnected and connected in a very short time. It lead to two things:

  1. A lot of requests are triggered on our auth endpoint. They don’t always arrive in correct order. This lead in having the message “Invalid signature: Expected HMAC SHA256 hex digest” because request x-1 is processed by Pusher while the socket id already changed to x
  2. Not all requests are sent. We found out that, from time to time, we get a request for socket x. But Pusher fail (“invalid signature”) expecting a signature for socket y. However we never see that socket id in our logs.

The reconnection attempts: Screenshot 2021-09-21 at 16 17 37

The logs on the auth endpoint: Screenshot 2021-09-21 at 16 41 40

The failure on iOS (see that we never received a request for 327215) Screenshot 2021-09-21 at 17 03 34

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Reactions: 2
  • Comments: 39 (17 by maintainers)

Most upvoted comments

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you’d like this issue to stay open please leave a comment indicating how this issue is affecting you. Thank you.

Has there been any update on this issue?

This is a joke. No news since 6 months. No news on my last comment. And the ticket get closed.

I just found out a way to partially reproduce the Invalid signature error: I had to put the app into the background, and then switch from Wifi to LTE, and back again to Wifi, then resume the app into the foreground. This results in a HMAC digest error which I think is the same as what you’re getting:

[PUSHER DEBUG] Network connection became unviable
2022-06-16 10:59:59.927034-0400 channels_ios_demo[88777:5227278] [tcp] nw_proto_tcp_route_init [C22.1:3] no mtu received
[PUSHER DEBUG] Network connection became unviable
2022-06-16 10:59:59.927858-0400 channels_ios_demo[88777:5227278] [tcp] nw_proto_tcp_route_init [C21.1:3] no mtu received
[PUSHER DEBUG] Network connection became unviable
2022-06-16 10:59:59.928613-0400 channels_ios_demo[88777:5227278] [tcp] nw_proto_tcp_route_init [C23.1:3] no mtu received
2022-06-16 10:59:59.931227-0400 channels_ios_demo[88777:5227278] Connection 24: encountered error(1:53)
...
...
State changed from disconnected to reconnecting
[PUSHER DEBUG] Attempting to reconnect after waiting 9.0 seconds (attempt 4)
State changed from reconnecting to connecting
[PUSHER DEBUG] Network connection became viable
[PUSHER DEBUG] websocketDidReceiveMessage {"event":"pusher:connection_established","data":"{\"socket_id\":\"135891.39615815\",\"activity_timeout\":120}"}
[PUSHER DEBUG] Socket established with socket ID: 135891.39615815
State changed from connecting to connected
[PUSHER DEBUG] sendEvent {"event":"pusher:subscribe","data":{"channel":"private-my-channel","auth":"dc9b99559fxxxxxx:5536608f52875b0c446a0c0826abc6c8373e0e73a7a35cf77c152755232aedd1"}}
[PUSHER DEBUG] Network connection became viable
[PUSHER DEBUG] websocketDidReceiveMessage {"event":"pusher:connection_established","data":"{\"socket_id\":\"135930.39523068\",\"activity_timeout\":120}"}
[PUSHER DEBUG] Socket established with socket ID: 135930.39523068
[PUSHER DEBUG] websocketDidReceiveMessage {"event":"pusher:error","data":{"code":null,"message":"Invalid signature: Expected HMAC SHA256 hex digest of 135930.39523068:private-my-channel, but got 5536608f52875b0c446a0c0826abc6c8373e0e73a7a35cf77c152755232aedd1"}}

The library connects twice upon resume, and there’s confusion between the client and server over which socket should be authenticated. We’re investigating why our library is queuing up the reconnection/resubscription, and I will update when we discover the cause.

We have a potential fix for this, which is currently in the testing stage.

We also have occasional issues with this. Are there any updates with fixing this?