Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Rails - Server Blocking on Action Cable

I have a Rails app that works perfectly in development. I have deployed to the server and the app loads and correctly shows its landing and about pages. However, when I go to a page with Action Cable, the server blocks. The last request out from the web page is Action Cable related, and further page actions (form submission, and even reloads) and not responded to.

I have isolated it to the server as attempting to load the site's main page from another browser does not work. Closing the tab where the request to Action Cable was first made results in the other page loading immediately (and all of the pending requests from the first page suddenly being processed).

I do not see any errors in production.log, but here is the part leading up to the hang:

I, [2018-01-24T21:12:38.601260 #9840]  INFO -- : [86b3fcc1-cebd-4d70-99ff-b6f9f147bc00]   Rendered collection of skill_checks/_skill_check.html.erb [5 times] (16.7ms)
I, [2018-01-24T21:12:38.601352 #9840]  INFO -- : [86b3fcc1-cebd-4d70-99ff-b6f9f147bc00]   Rendered rooms/show.html.erb within layouts/application (26.6ms)
I, [2018-01-24T21:12:38.602314 #9840]  INFO -- : [86b3fcc1-cebd-4d70-99ff-b6f9f147bc00] Completed 200 OK in 32ms (Views: 26.7ms | ActiveRecord: 1.8ms)
I, [2018-01-24T21:12:38.740061 #9840]  INFO -- : [5a06a7d8-a4a5-4ab4-8287-377dfa3447fe] Started GET "/cable" for 65.99.102.74 at 2018-01-24 21:12:38 +0000
I, [2018-01-24T21:12:38.740860 #9840]  INFO -- : [5a06a7d8-a4a5-4ab4-8287-377dfa3447fe] Started GET "/cable/" [WebSocket] for 65.99.102.74 at 2018-01-24 21:12:38 +0000
I, [2018-01-24T21:12:38.740970 #9840]  INFO -- : [5a06a7d8-a4a5-4ab4-8287-377dfa3447fe] Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: upgrade, HTTP_UPGRADE: websocket)
I, [2018-01-24T21:12:38.794498 #9840]  INFO -- : RoomsChannel is transmitting the subscription confirmation
I, [2018-01-24T21:12:38.795245 #9840]  INFO -- : RoomsChannel is streaming from room_helloworld

Once I close the offending tab, load continues (in this case, of a javascript request that was triggered on page reload) as follows:

I, [2018-01-24T21:15:55.109087 #9840]  INFO -- : Finished "/cable/" [WebSocket] for 65.99.102.74 at 2018-01-24 21:15:55 +0000
I, [2018-01-24T21:15:55.109342 #9840]  INFO -- : RoomsChannel stopped streaming from room_helloworld
I, [2018-01-24T21:15:55.110922 #9840]  INFO -- : [2cf5cc53-2f44-42a9-be30-496bb80646a0] Started GET "/rooms/helloworld?update=true" for 65.99.102.74 at 2018-01-24 21:15:55 +0000
I, [2018-01-24T21:15:55.112841 #9840]  INFO -- : [2cf5cc53-2f44-42a9-be30-496bb80646a0] Processing by RoomsController#show as HTML

I've truncated the remainder; there were no failures or anything else of interest in there.

I do have a redis server running on the same server and have put its port information into config/cable.yml under the production: section.

I believe that Rails can see it as I haven't seen any errors. Additionally, to verify this I connected to redis through redis-cli and subscribed to a channel, and then through the Rails console sent a broadcast message to that channel and verified receipt.

Update: I've tried a few different builds to isolate the issue. Here's what I now know:

  • I removed my only call to ActionCable.server.broadcast, so that isn't the source of the block.
  • I added javascript console logs to connected, disconnected, and received. The client does successfully subscribe.
  • I tried a build where I removed the App.cable.subscriptions.create from the client. While there is no websocket connection in this case (as you would expect), the server does not block/hang.

Given the above, I am certain this has to do with ActionCable, though I'm not sure if it has anything to do with my redis configuration.

like image 444
El Tea Avatar asked Jan 24 '18 21:01

El Tea


People also ask

How do I use action cable in rails?

Action Cable can run alongside your Rails application. For example, to listen for WebSocket requests on /websocket, specify that path to config.action_cable.mount_path: You can use ActionCable.createConsumer () to connect to the cable server if action_cable_meta_tag is invoked in the layout.

What is the action cable server?

The Action Cable server implements the Rack socket hijacking API, thereby allowing the use of a multi-threaded pattern for managing connections internally, irrespective of whether the application server is multi-threaded or not. Accordingly, Action Cable works with popular servers like Unicorn, Puma, and Passenger.

How does action cable work with Redis?

For every instance of your server you create, and for every worker your server spawns, you will also have a new instance of Action Cable, but the Redis or PostgreSQL adapter keeps messages synced across connections. The cable servers can be separated from your normal application server.

What is action cable WebSockets?

Action Cable uses WebSockets instead of the HTTP request-response protocol. Both Action Cable and WebSockets introduce some less familiar terminology: Connections form the foundation of the client-server relationship. A single Action Cable server can handle multiple connection instances. It has one connection instance per WebSocket connection.


1 Answers

This turned out the be the behaviour you get if you haven't set the following lines inside of your nginx conf file (inside of the server section):

location /cable {
    passenger_app_group_name your_app_websocket;
    passenger_force_max_concurrent_requests_per_process 0;
}

where, if your app name is "chat", the first line would read:

passenger_app_group_name chat_action_cable

Which, frankly, I'm not sure where is defined, but it may be part of the Rails magic.

like image 100
El Tea Avatar answered Sep 21 '22 22:09

El Tea