rails icon indicating copy to clipboard operation
rails copied to clipboard

Action Cable client goes in a connection loop if you subscribe multiple times to the same channel

Open ProGM opened this issue 1 year ago • 0 comments

Steps to reproduce

You can just start from a fresh rails new [project-name] installation. Channel code:

class ArticleChannel < ApplicationCable::Channel
  def subscribed
    stream_from "ArticleChannel"
  end

  def unsubscribed
    # Any cleanup needed when channel is unsubscribed
  end
end

Javascript code:

import consumer from "channels/consumer"

function subscribe() {
	return consumer.subscriptions.create('ArticleChannel', {
		connected() {
			console.log('connected');
			// Called when the subscription is ready for use on the server
		},

		disconnected() {
			console.log('disconnected');
			// Called when the subscription has been terminated by the server
		},

		received(data) {
			console.log('received', data);
			// Called when there's incoming data on the websocket for this channel
		}
	});
}

setTimeout(() => {
	subscribe();
}, 3000);

setTimeout(() => {
	subscribe();
}, 4000);

Expected behavior

Any of these options could be considered an expected behavior:

  • Everything just works™, both subscriptions receive notification from that channel and no error is raised
  • The second subscription.create(...) raises some kind of error, notifying that the channel is already connected
  • The second subscription.create(...) returns the same instance of Subscription and writes a console.warning in console

Actual behavior

The second subscriptions triggers a connection loop.

Example logs with ActionCable.logger.enabled = true.

[ActionCable] Opening WebSocket, current state is null, subprotocols: actioncable-v1-json,actioncable-unsupported 1660037219747
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] ConnectionMonitor started. stale threshold = 6 s 1660037219748
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] WebSocket onopen event, using 'actioncable-v1-json' subprotocol 1660037219758
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] ConnectionMonitor recorded connect 1660037219759
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor guaranteeing {"channel":"ArticleChannel"} 1660037219760
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] Subscription confirmed {"channel":"ArticleChannel"} 1660037219762
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor forgetting {"channel":"ArticleChannel"} 1660037219762
article_channel-b29f3f7bf31169dfadd26c7747a46706d4992a1fd842de8268f206c5f0a0fe45.js:6 connected
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor guaranteeing {"channel":"ArticleChannel"} 1660037220744
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor resubscribing {"channel":"ArticleChannel"} 1660037221248
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor already guaranteeing {"channel":"ArticleChannel"} 1660037221248
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor resubscribing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor already guaranteeing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor resubscribing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor already guaranteeing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor resubscribing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
[ActionCable] SubscriptionGuarantor already guaranteeing {"channel":"ArticleChannel"} 1660037221753
actioncable.esm-e01089c3ec4fe7817fa9abcad06cab6bdc387f95f0ca6aab4bf7ba7537f70690.js:10
... and so on, forever...

System configuration

Rails version: 7.0.3.1

Ruby version: 3.1

Possible solutions

This issue happens because the identifier of both subscriptions is the same. Since Rails (ActionCable) doesn't answer to any subsequential command "subscribe" from the same client (in this case: {"command":"subscribe","identifier":"{\"channel\":\"ArticleChannel\"}"}), the SubscriptionGuarantor considers the connection failed and retries to connect after 500ms.

I see various options to fix this:

  • Raise an exception when trying to create a subscription with the same identifier
  • Add a random/uuid to the identifier when connecting, so two connection would not share the same identifier? (I've already tested it, and it seems to fix)

Would you accept a PR from me regarding this?

ProGM avatar Aug 09 '22 09:08 ProGM