solved: Redis/Sidekiq config error? Infinite error loop on OTB JSP on Heroku: "ERR max number of clients reached"

(duplicate posted as issue on the JSP github issues board)

The handy "deploy to Heroku" video does not mention or show turning "on" the Redis worker.

1 - Started with a brand new, fresh, "virgin" copy of JSP (so none of my custom code added).

2 - Followed the steps in the video (edited database.yml to change database name, editied but did not change production.yml.enc, set the Heroku RAILS_MASTER_KEY to the value in config/credentials/production.key

2 - Before making my first commit and pushing it to Heroku, I did ONE more step, though... on my local dev't server I also set the "Jumpstart Config" > "Background Job Processor" to "Sidekiq".

3 THEN I committed changes, pushed back up to my "virgin" github, then pushed to heroku.

The web app on Heroku fires up fine.

BUT... if I turn ON the worker dyno while watching Heroku logs on my Mac heroku logs -t the logs show infinite loop of worker errors related to redis, this same thing over and over:

In this log I can watch as the worker first starts up boots rails then immediately hits the error, which repeats forever (until I turn off the worker dyno):

worker turns on:

2021-06-03T23:24:38.481403+00:00 app[api]: Scaled to console@0:Free rake@0:Free web@1:Free worker@1:Free by user xxxxxxxxxx
2021-06-03T23:24:51.089424+00:00 heroku[worker.1]: Starting process with command `bundle exec sidekiq`
2021-06-03T23:24:51.949205+00:00 heroku[worker.1]: State changed from starting to up

worker starts to boot rails:

2021-06-03T23:25:06.199070+00:00 app[worker.1]: pid=4 tid=3c4 INFO: Booted Rails 6.1.3.2 application in production environment
2021-06-03T23:25:06.199184+00:00 app[worker.1]: pid=4 tid=3c4 INFO: Running in ruby 3.0.1p64 (2021-04-05 revision 0fb782ee38) [x86_64-linux]
2021-06-03T23:25:06.199231+00:00 app[worker.1]: pid=4 tid=3c4 INFO: See LICENSE and the LGPL-3.0 for licensing details.
2021-06-03T23:25:06.199267+00:00 app[worker.1]: pid=4 tid=3c4 INFO: Upgrade to Sidekiq Pro for more features and support: https://sidekiq.org
2021-06-03T23:25:06.199826+00:00 app[worker.1]: pid=4 tid=3c4 INFO: Booting Sidekiq 6.2.1 with redis options {:url=>"redis://:REDACTED@ec2-54-85-51-72.compute-1.amazonaws.com:10019"}

something STARTS ... this is the START of the infinite error LOOP:

2021-06-03T23:25:06.326273+00:00 app[worker.1]: pid=4 tid=142c class=ActiveStorage::AnalyzeJob jid=f98ab729ca1b81971b019ef5 INFO: start

with the specific error trace:

2021-06-03T23:25:06.335100+00:00 app[worker.1]: pid=4 tid=143s WARN: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:132:in `call'
2021-06-03T23:25:06.335102+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:113:in `block in connect'
2021-06-03T23:25:06.335102+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:313:in `with_reconnect'
2021-06-03T23:25:06.335102+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:111:in `connect'
2021-06-03T23:25:06.335103+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:294:in `with_socket_timeout'
2021-06-03T23:25:06.335103+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis/client.rb:225:in `call_with_timeout'
2021-06-03T23:25:06.335104+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis.rb:1224:in `block in _bpop'
2021-06-03T23:25:06.335104+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis.rb:69:in `block in synchronize'
2021-06-03T23:25:06.335105+00:00 app[worker.1]: /app/vendor/ruby-3.0.1/lib/ruby/3.0.0/monitor.rb:202:in `synchronize'
2021-06-03T23:25:06.335105+00:00 app[worker.1]: /app/vendor/ruby-3.0.1/lib/ruby/3.0.0/monitor.rb:202:in `mon_synchronize'
2021-06-03T23:25:06.335105+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis.rb:69:in `synchronize'
2021-06-03T23:25:06.335106+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis.rb:1221:in `_bpop'
2021-06-03T23:25:06.335106+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/redis-4.2.5/lib/redis.rb:1266:in `brpop'
2021-06-03T23:25:06.335107+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/fetch.rb:47:in `block in retrieve_work'
2021-06-03T23:25:06.335107+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq.rb:98:in `block in redis'
2021-06-03T23:25:06.335131+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/connection_pool-2.2.5/lib/connection_pool.rb:63:in `block (2 levels) in with'
2021-06-03T23:25:06.335132+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/connection_pool-2.2.5/lib/connection_pool.rb:62:in `handle_interrupt'
2021-06-03T23:25:06.335132+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/connection_pool-2.2.5/lib/connection_pool.rb:62:in `block in with'
2021-06-03T23:25:06.335133+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/connection_pool-2.2.5/lib/connection_pool.rb:59:in `handle_interrupt'
2021-06-03T23:25:06.335133+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/connection_pool-2.2.5/lib/connection_pool.rb:59:in `with'
2021-06-03T23:25:06.335133+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq.rb:95:in `redis'
2021-06-03T23:25:06.335134+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/fetch.rb:47:in `retrieve_work'
2021-06-03T23:25:06.335134+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/processor.rb:83:in `get_one'
2021-06-03T23:25:06.335135+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/processor.rb:95:in `fetch'
2021-06-03T23:25:06.335135+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/processor.rb:77:in `process_one'
2021-06-03T23:25:06.335136+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/processor.rb:68:in `run'
2021-06-03T23:25:06.335136+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/util.rb:43:in `watchdog'
2021-06-03T23:25:06.335136+00:00 app[worker.1]: /app/vendor/bundle/ruby/3.0.0/gems/sidekiq-6.2.1/lib/sidekiq/util.rb:52:in `block in safe_thread'

log repeats from the "something STARTS...." point above

Sigh. The answer is that the JSP-provided Procfile is not correct for Heroku, when using Sidekiq for the background worker and the free Redis plan (the plan shown in your Heroku deployment video).

Needs to have -c 2 added, eg, bundle exec sidekiq -c 2

IMO JSP should add this factoid to your "deployment" section under Heroku, and, if not revising actual Procfile then add a comment to the Procfile:

# Procfile
web: bundle exec rails s
worker: bundle exec sidekiq
# For  Heroku 'free' Redis use:
# worker: bundle exec sidekiq -c 2

This was helpful:
 https://betterprogramming.pub/how-to-use-sidekiq-in-rails-6-f3b76678362d


Stephen Ierodiaconou
Hey JPW, you might find it best to raise this directly with Chris or create a PR, sounds like a useful observation!
Yes, I did post an issue on the JSP github issues page.
Notifications
You’re not receiving notifications from this thread.
Subscribe
© 2022 GoRails, LLC