IOS issue with ActionCable not delivering messages

Question

We have noticed, that IOS users with version 17.0.x while using the ActionCable on Rails almost 50% of the messages were not delivered.

We are getting the following messages.

D 2023-10-06T07:21:42.075Z context=node sid=kNJYv6SokFfI9dy9T1E9mK Perform result: &{[] false [] false []}
D 2023-10-06T07:21:42.198Z context=node sid=kNJYv6SokFfI9dy9T1E9mK Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"action":"read"}}
W 2023-10-06T07:21:42.198Z context=node sid=kNJYv6SokFfI9dy9T1E9mK Unknown subscription {"channel":"ConversationChannel","conversation_id":1512}
D 2023-10-06T07:25:48.772Z context=node sid=kNJYv6SokFfI9dy9T1E9mK Websocket close error: websocket: close 1006 (abnormal closure): unexpected EOF
D 2023-10-06T07:25:48.772Z context=node sid=kNJYv6SokFfI9dy9T1E9mK websocket session completed
D 2023-10-06T07:25:48.772Z channel={"conversation_id":1512,"channel":"ConversationChannel"} context=hub sid=kNJYv6SokFfI9dy9T1E9mK Unsubscribed             
D 2023-10-06T07:25:48.772Z context=hub sid=kNJYv6SokFfI9dy9T1E9mK Unregistered             
D 2023-10-06T07:25:48.772Z context=node sid=kNJYv6SokFfI9dy9T1E9mK Disconnect {"current_user":"Z2lkOi8vbXlqb2Jub3cvVXNlci8zMzY4"} /cable [{"conversation_id":1512,"channel":"ConversationChannel"}]
D 2023-10-06T07:25:48.774Z context=rpc Disconnect response: status:SUCCESS 
D 2023-10-06T07:26:50.129Z context=rpc Authenticate response: status:SUCCESS identifiers:"{\"current_user\":\"Z2lkOi8vbXlqb2Jub3cvVXNlci8zMzY4\"}" transmissions:"{\"type\":\"welcome\"}" 
D 2023-10-06T07:26:50.129Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg websocket session established
D 2023-10-06T07:26:50.129Z context=hub sid=mAfQYjytdw5yO1QHHTJ1dg Registered with identifiers: {"current_user":"Z2lkOi8vbXlqb2Jub3cvVXNlci8zMzY4"}
D 2023-10-06T07:26:50.348Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{subscribe {"channel":"ConversationChannel","conversation_id":1512} }
D 2023-10-06T07:26:50.354Z context=rpc Command response: status:SUCCESS streams:"conversation_1512" transmissions:"{\"identifier\":\"{\\\"channel\\\":\\\"ConversationChannel\\\",\\\"conversation_id\\\":1512}\",\"type\":\"confirm_subscription\"}" 
D 2023-10-06T07:26:50.354Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Subscribed to channel: {"channel":"ConversationChannel","conversation_id":1512}
D 2023-10-06T07:26:50.354Z channel={"channel":"ConversationChannel","conversation_id":1512} context=hub sid=mAfQYjytdw5yO1QHHTJ1dg stream=conversation_1512 Subscribed               
D 2023-10-06T07:26:50.426Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"action":"read"}}
D 2023-10-06T07:26:50.447Z context=rpc Command response: status:SUCCESS 
D 2023-10-06T07:26:50.447Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Perform result: &{[] false [] false []}
D 2023-10-06T07:27:05.902Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"text":"Dsdwasdad","uuid":"EFFFEADD-40D3-4D68-8E39-1303F7E68B30","action":"send_message"}}
D 2023-10-06T07:27:05.994Z context=pubsub Incoming pubsub message from Redis: {"stream":"conversation_1512","data":"{\"action\":\"new_message\",\"payload\":{\"msg\":{\"text\":\"Dsdwasdad\"}}}"}
D 2023-10-06T07:27:05.994Z context=node Incoming pubsub message: &{conversation_1512 {"action":"new_message","payload":{"msg":{"text":"Dsdwasdad",}}}}
D 2023-10-06T07:27:05.994Z context=hub stream=conversation_1512 Broadcast message: {"action":"new_message","payload":{"msg":{"text":"Dsdwasdad",}}}}
D 2023-10-06T07:27:05.997Z context=rpc Command response: status:SUCCESS 
D 2023-10-06T07:27:05.997Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Perform result: &{[] false [] false []}
D 2023-10-06T07:27:06.130Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"action":"read"}}
D 2023-10-06T07:27:06.150Z context=rpc Command response: status:SUCCESS 
D 2023-10-06T07:27:06.150Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Perform result: &{[] false [] false []}
D 2023-10-06T07:27:07.824Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"conversation_id":1512,"channel":"ConversationChannel"} {"uuid":"D192F95C-C20E-4B12-9D83-9076EE9CA378","text":"Dasdw","action":"send_message"}}
W 2023-10-06T07:27:07.824Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Unknown subscription {"conversation_id":1512,"channel":"ConversationChannel"}
D 2023-10-06T07:27:10.754Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"conversation_id":1512,"channel":"ConversationChannel"} {"text":"Dassss","uuid":"1FD4DF7F-6DD1-4326-AA50-87CFA917C7A7","action":"send_message"}}
W 2023-10-06T07:27:10.754Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Unknown subscription {"conversation_id":1512,"channel":"ConversationChannel"}
D 2023-10-06T07:27:13.166Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"uuid":"E4053CD5-A614-4D51-8927-5D3E6D611875","text":"Dddwdwa","action":"send_message"}}
D 2023-10-06T07:27:13.239Z context=pubsub Incoming pubsub message from Redis: {"stream":"conversation_1512","data":"{\"action\":\"new_message\",\"payload\":{\"msg\":{\"text\":\"Dddwdwa\",}}
D 2023-10-06T07:27:13.239Z context=node Incoming pubsub message: &{conversation_1512 {"action":"new_message","payload":{"msg":{"text":"Dddwdwa""conversation_id":1512,"timestamp":"2023-10-06T07:27:13+00:00","uuid":"E4053CD5-A614-4D51-8927-5D3E6D611875","type":{"name":"text","text":"Dddwdwa"}}}}
D 2023-10-06T07:27:13.239Z context=hub stream=conversation_1512 Broadcast message: {"action":"new_message","payload":{"msg":{"text":"Dddwdwa","conversation_id":1512,"timestamp":"2023-10-06T07:27:13+00:00","uuid":"E4053CD5-A614-4D51-8927-5D3E6D611875","type":{"name":"text","text":"Dddwdwa"} }}}
D 2023-10-06T07:27:13.241Z context=rpc Command response: status:SUCCESS 
D 2023-10-06T07:27:13.241Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Perform result: &{[] false [] false []}
D 2023-10-06T07:27:13.375Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"action":"read"}}
D 2023-10-06T07:27:13.396Z context=rpc Command response: status:SUCCESS 
D 2023-10-06T07:27:13.396Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Perform result: &{[] false [] false []}
D 2023-10-06T07:27:16.662Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"conversation_id":1512,"channel":"ConversationChannel"} {"action":"send_message","uuid":"E5618963-1CA1-4EB3-BAB9-196590F35A7B","text":"Asdwadasdwa"}}
W 2023-10-06T07:27:16.662Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Unknown subscription {"conversation_id":1512,"channel":"ConversationChannel"}
D 2023-10-06T07:27:26.078Z context=node sid=mAfQYjytdw5yO1QHHTJ1dg Incoming message: &{message {"channel":"ConversationChannel","conversation_id":1512} {"text":"Dsdsds\n","uuid":"C52C1FA9-B495-44C4-B4E4-2A8D97AEE4B9","action":"send_message"}}
D 2023-10-06T07:27:26.153Z context=pubsub Incoming pubsub message from Redis: {"stream":"conversation_1512","data":"{\"action\":\"new_message\",\"payload\":{\"msg\":{\"text\":\"Dsdsds\\n\"}

A screenshot from the test performed attached.

enter image description here

As a results, those messages not delivered to IOS users.

Library Versions

Server Side : Rails v6,AnyCable v0.6.5

IOS Lib for Client Websocket: Starscream (initially on v3.1.1), then on v4.0.6 issue persists.

We have pinpointed that the issue might be on the IOS version, as on previous versions 16.x, 15.x is working without any issue.Moreover, on Android and Web clients there is no issue at all.

Any insights/suggestions will be really helpful here.

Answer 1

Here is the problem:

Subscribed to channel: {"channel":"ConversationChannel","conversation_id":1512}

...

Unknown subscription {"conversation_id":1512,"channel":"ConversationChannel"}

The order of the fields in the identifier (which is the JSON-encoded object) is different.

AnyCable treats identifiers as strings, it has no assumptions on what's inside (i.e., we don't decode JSON to look up a channel). See the protocol spec.

Which client-side library do you use? It seems that it doesn't re-use the identifier and instead performs JSON encoding of the {channel, conversation_id} object every time it sends a command—which is wrong.

Also,

AnyCable v0.6.5

Is it a gem version? Anyway, it's too old (though not related, I think)