0

Heroku returns error for connecting to Redis. I'm using Action Cable for a messaging site, which works FINE in local development.

I'm using RedisToGo

I added this to my production.rb:

config.middleware.use ChatActionCable
config.web_socket_server_url = "wss://my-app-name-here.herokuapp.com/cable"
config.action_cable.allowed_request_origins = ['https://my-app-name-here.herokuapp.com', 'http://my-app-name-here.herokuapp.com']

ChatActionCable refers to my middleware chat_action_cable.rb, which i added while following this guide. here is that code:

class ChatActionCable < ActionCable::Connection::WebSocket
  def initialize(app, options={})
    @app = app
 end

  def call(env)
    if ::WebSocket::Driver.websocket?(env)
      ActionCable.server.call(env)
    else
      @app.call(env)
    end
  end
end

my initializers/redis.rb:

uri = URI.parse(ENV["REDISTOGO_URL"] || "redis://localhost:6379/" )
REDIS = Redis.new(:url => uri)

my cable.yml:

development:
  adapter: async

test:
  adapter: async

production: &production
  :adapter: redis
  :url: redis://redistogo:<my-password-is-here>@barreleye.redistogo.com:11263/
  :host: barreleye.redistogo.com
  :port: 11263
  :password: <my-password>
  :inline: true
  :timeout: 1

here is the full log from Heroku:

2017-05-14T04:26:46.393702+00:00 heroku[web.1]: State changed from starting to up
2017-05-14T04:26:46.608962+00:00 app[web.1]: I, [2017-05-14T04:26:46.608852 #4]  INFO -- : [4d655163-18cd-49dd-8847-2bd483872664] Started GET "/cable" for 73.96.114.190 at 2017-05-14 04:26:46 +0000
2017-05-14T04:26:46.647328+00:00 app[web.1]: I, [2017-05-14T04:26:46.647233 #4]  INFO -- : [4d655163-18cd-49dd-8847-2bd483872664] Started GET "/cable/" [WebSocket] for 73.96.114.190 at 2017-05-14 04:26:46 +0000
2017-05-14T04:26:46.647431+00:00 app[web.1]: I, [2017-05-14T04:26:46.647368 #4]  INFO -- : [4d655163-18cd-49dd-8847-2bd483872664] Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: websocket)
2017-05-14T04:26:47.151764+00:00 heroku[router]: at=info method=GET path="/cable" host=teamgo.herokuapp.com request_id=4d655163-18cd-49dd-8847-2bd483872664 fwd="73.96.114.190" dyno=web.1 connect=0ms service=541ms status=101 bytes=194 protocol=https
2017-05-14T04:26:47.147989+00:00 app[web.1]: I, [2017-05-14T04:26:47.147897 #4]  INFO -- : Finished "/cable/" [WebSocket] for 73.96.114.190 at 2017-05-14 04:26:47 +0000
2017-05-14T04:26:48.744259+00:00 app[web.1]: I, [2017-05-14T04:26:48.744149 #4]  INFO -- : [cbddfc23-c1ec-4f35-ad62-6afbb846a1d3] Started GET "/cable" for 73.96.114.190 at 2017-05-14 04:26:48 +0000
2017-05-14T04:26:48.745125+00:00 app[web.1]: I, [2017-05-14T04:26:48.745015 #4]  INFO -- : [cbddfc23-c1ec-4f35-ad62-6afbb846a1d3] Started GET "/cable/" [WebSocket] for 73.96.114.190 at 2017-05-14 04:26:48 +0000
2017-05-14T04:26:48.745237+00:00 app[web.1]: I, [2017-05-14T04:26:48.745168 #4]  INFO -- : [cbddfc23-c1ec-4f35-ad62-6afbb846a1d3] Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: websocket)
2017-05-14T04:26:48.851585+00:00 app[web.1]: Exiting
2017-05-14T04:26:48.852553+00:00 app[web.1]: /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:345:in `rescue in establish_connection': Error connecting to Redis on localhost:6379 (Errno::ECONNREFUSED) (Redis::CannotConnectError)
2017-05-14T04:26:48.852558+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:331:in `establish_connection'
2017-05-14T04:26:48.852561+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:101:in `block in connect'
2017-05-14T04:26:48.852562+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:293:in `with_reconnect'
2017-05-14T04:26:48.852584+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:100:in `connect'
2017-05-14T04:26:48.852585+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:276:in `with_socket_timeout'
2017-05-14T04:26:48.852586+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:133:in `call_loop'
2017-05-14T04:26:48.852588+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/subscribe.rb:43:in `subscription'
2017-05-14T04:26:48.852589+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/subscribe.rb:12:in `subscribe'
2017-05-14T04:26:48.852591+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:2765:in `_subscription'
2017-05-14T04:26:48.852593+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:2143:in `block in subscribe'
2017-05-14T04:26:48.852595+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:58:in `block in synchronize'
2017-05-14T04:26:48.852608+00:00 app[web.1]:    from /app/vendor/ruby-2.3.4/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
2017-05-14T04:26:48.852609+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:58:in `synchronize'
2017-05-14T04:26:48.852611+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:2142:in `subscribe'
2017-05-14T04:26:48.852618+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/actioncable-5.0.1/lib/action_cable/subscription_adapter/redis.rb:75:in `block in listen'
2017-05-14T04:26:48.852620+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis/client.rb:293:in `with_reconnect'
2017-05-14T04:26:48.852626+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:64:in `block in with_reconnect'
2017-05-14T04:26:48.852628+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:58:in `block in synchronize'
2017-05-14T04:26:48.852634+00:00 app[web.1]:    from /app/vendor/ruby-2.3.4/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
2017-05-14T04:26:48.852650+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:58:in `synchronize'
2017-05-14T04:26:48.852652+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:63:in `with_reconnect'
2017-05-14T04:26:48.852654+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/redis-3.3.3/lib/redis.rb:70:in `without_reconnect'
2017-05-14T04:26:48.852665+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/actioncable-5.0.1/lib/action_cable/subscription_adapter/redis.rb:72:in `listen'
2017-05-14T04:26:48.852695+00:00 app[web.1]:    from /app/vendor/bundle/ruby/2.3.0/gems/actioncable-5.0.1/lib/action_cable/subscription_adapter/redis.rb:146:in `block in ensure_listener_running'
2017-05-14T04:26:48.928202+00:00 heroku[web.1]: Process exited with status 1
2017-05-14T04:26:48.859559+00:00 heroku[router]: at=info method=GET path="/cable" host=teamgo.herokuapp.com request_id=cbddfc23-c1ec-4f35-ad62-6afbb846a1d3 fwd="73.96.114.190" dyno=web.1 connect=1ms service=113ms status=101 bytes=174 protocol=https
2017-05-14T04:26:48.940649+00:00 heroku[web.1]: State changed from up to crashed
2017-05-14T04:26:56.135087+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=GET path="/cable" host=teamgo.herokuapp.com request_id=e7bbe5e8-ed74-47ba-9da0-d58d08bd0a7e fwd="73.96.114.190" dyno= connect= service= status=503 bytes= protocol=https

bundle exec rake middleware returns this:

use Rack::Sendfile
use ActionDispatch::Static
use ActionDispatch::Executor
use ActiveSupport::Cache::Strategy::LocalCache::Middleware
use Rack::Runtime
use Rack::MethodOverride
use ActionDispatch::RequestId
use Sprockets::Rails::QuietAssets
use Rails::Rack::Logger
use ActionDispatch::ShowExceptions
use WebConsole::Middleware
use ActionDispatch::DebugExceptions
use ActionDispatch::RemoteIp
use ActionDispatch::Reloader
use ActionDispatch::Callbacks
use ActiveRecord::Migration::CheckPending
use ActionDispatch::Cookies
use ActionDispatch::Session::CookieStore
use ActionDispatch::Flash
use Rack::Head
use Rack::ConditionalGet
use Rack::ETag
use Warden::Manager
run BudgetTracker::Application.routes
Jacob Hixon
  • 133
  • 1
  • 9

2 Answers2

1

SOLUTION: This issue is a confirmed bug in Rails 5.0.1+ as shown here in rails issue #28362

the folks working on the puma side of this issue (puma issue #1189) appear to have merged the fix in with the updated master and Rails 5.0.3 release.

UPDATE: I can confirm, after recreating my project in a new project running Rails v5.0.3, that the bug has in fact been fixed in 5.0.3. The app is successfully implementing Action Cable and Web Socket functionality on Heroku. I hope people find this post and see this answer if they have similar issues.

Jacob Hixon
  • 133
  • 1
  • 9
0

It looks to me like you are either failing to authenticate with your Redis instance, or it simply isn't reachable for some reason. Have you tried logging into the Rails console and debugging manually?

I would also take a look at your middleware stack via bundle exec rake middleware as it may be that you need to do an config.middleware.insert_before rather than a config.middleware.use.

  • I have not tried debugging in Rails Console. I'm still pretty new to Redis and Action Cable and all this, so would you be able to offer some suggestions for how to go about debugging this in the console? As for the middleware, I have updated my post above with the results of calling `bundle exec rake middleware` – Jacob Hixon May 14 '17 at 19:41