7

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.

El Tea
  • 1,206
  • 12
  • 21

1 Answers1

8

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.

El Tea
  • 1,206
  • 12
  • 21
  • 1
    I can't thank you enough for solving my problem. I was experiencing hanging requests on production (not good!) and couldn't find out the problem. Your answer led me to this article from Passenger: https://www.phusionpassenger.com/library/config/nginx/action_cable_integration. Adding this new `location` block runs Action Cable in a separate process and stops it from blocking normal HTTP requests. The `passenger_app_group_name` can actually be any unique value, so it isn't Rails magic! – Alexander Sep 03 '19 at 15:53
  • Thankfully this worked for me, i was facing connection timeout when more than 7 clients are connected and now i tested with more than 20 and it's going fine, This solved my problem – Amir El-Bashary Oct 02 '19 at 14:14