Rails & ActionCable 1.8hr network request time on localhost / High Response Time on Heroku

Question

The Network tab in Chrome shows /cable requests that fluctuate between seconds and hours on localhost:

...and then this insane domino stack of "pending" requests:

On Heroku with a Puma server and a 512 MB dyno, I get High Response Time warnings on the /cable endpoint. Here is an example of the log entry:

25 Dec 2019 14:13:31.061299 <158>1 2019-12-25T22:13:28.421009+00:00 heroku router - - at=info method=GET path="/cable" host=www.######.com request_id=#### fwd="####" dyno=web.1 connect=1ms service=531114ms status=101 bytes=174 protocol=https High Response Time

In all cases, I am the only person using the app. I've seen maybe max 3-4 other people experiencing this problem with ActionCable, but none of them seem to have any solution, and I am at my wits end. I've looked into AnyCable and Iodine, but AnyCable isn't working and Iodine does not solve my problem. What else could possibly be causing this?

Expected behavior: /cable requests should be processed in a few ms.

Actual behavior: some /cable requests are being processed 80 years later, and then hundreds of others are stuck in a pending state.

System configuration: Ruby version: 2.5.0, Rails version: 5.2.0, Puma version: 4.3.1

channels/application_cable/channel.rb

module ApplicationCable
 class Channel < ActionCable::Channel::Base
 end
end

channels/application_cable/connection.rb

module ApplicationCable
 class Connection < ActionCable::Connection::Base
  identified_by :current_user

  def connect
   self.current_user = find_verified_user
   logger.add_tags 'ActionCable', current_user.username
  end

  protected
  def find_verified_user
   if verified_user = User.find_by(id: cookies.signed['user.id'])
    verified_user
   else
    reject_unauthorized_connection
   end  
  end
 end
end

channels/messages_channel.rb

class MessagesChannel < ApplicationCable::Channel
 def subscribed
  stream_from "user_#{current_user.id}_messages_channel"
 end

 def unsubscribed
  stop_all_streams
 end

 def speak(data)
  Message.create! body: data['message'], conversation_id: data['conversation_id'], user_id: current_user.id
 end
end

javascripts/channels/messages.coffee

App.messages = App.cable.subscriptions.create "MessagesChannel",
 connected: ->
  console.log 'Connected'

 disconnected: ->
  console.log 'Disconnected'

 received: (data) ->
  console.log 'Received'
  $("[data-conversation-id='" + data.conversation_id + "']").append(data.message)
  console.log 'Received'
  $("#messages").append(data.message)

 speak: (message, conversation_id) ->
  @perform 'speak', message: message, conversation_id: conversation_id

$(document).on 'turbolinks:load', ->
 submit_message()
 scroll_bottom()

submit_message = () ->
 $('#response').on 'keydown', (event) ->
  if event.keyCode is 13
   message = event.target.value
   conversation_id = $("#messages").data("conversation-id")
   App.messages.speak(message, conversation_id)
   event.target.value = ""
   event.preventDefault()

scroll_bottom = () ->
 if $('#messages').length > 0
 $('#messages').scrollTop($('#messages')[0].scrollHeight)

models/messages.rb

class Message < ApplicationRecord
 after_create_commit { MessageBroadcastWorker.perform_async self.id }
end

workers/message_broadcast_worker.rb

class MessageBroadcastWorker
 include Sidekiq::Worker

 def perform(message_id)
  message = Message.find message_id
  user = message.user
  ActionCable.server.broadcast("user_#{user.id}_messages_channel", message: render_message(message, user))
 end

 private
 def render_message(message, user)
  ApplicationController.renderer.render(partial: 'messages/message', locals: { message: message, user: user })
 end
end

Answer 1

The solution is to turn off the alert on Heroku logentries. The /cable request is not polling the server for updates, it's establishing a single request and then keeping it open until the user signs out or leaves the site.