I have a project I’m working on that I’m trying to get sidekiq working with. I have it working fine in my dev environment, but when I try to deploy it to fly, upstash gets to the limit of 10,000 requests in just a few minutes.
In my toml file I have
[processes]
web = "bin/rails fly:server"
worker = "bundle exec sidekiq"
Is there a way of viewing the logs of the workers? How do I view sidekiq’s logs in production?
Thanks Brad. I’m still not sure how to view sidekiq logs, but this is what I’m getting in my console logs.
2023-02-01T04:39:40Z app[0100acd1] sin [info]2023-02-01T04:39:40.015Z pid=520 tid=1uqs WARN: Your Redis network connection is performing extremely poorly.
2023-02-01T04:39:40Z app[0100acd1] sin [info]Last RTT readings were [160323, 160342, 160355, 160399, 160540], ideally these should be < 1000.
2023-02-01T04:39:40Z app[0100acd1] sin [info]Ensure Redis is running in the same AZ or datacenter as Sidekiq.
2023-02-01T04:39:40Z app[0100acd1] sin [info]If these values are close to 100,000, that means your Sidekiq process may be
2023-02-01T04:39:40Z app[0100acd1] sin [info]CPU-saturated; reduce your concurrency and/or see https://github.com/mperham/sidekiq/discussions/5039
2023-02-01T04:40:32Z app[0100acd1] sin [info]2023-02-01T04:40:32.450Z pid=520 tid=1uqs WARN: Your Redis network connection is performing extremely poorly.
2023-02-01T04:40:32Z app[0100acd1] sin [info]Last RTT readings were [161692, 161695, 162918, 161576, 161682], ideally these should be < 1000.
2023-02-01T04:40:32Z app[0100acd1] sin [info]Ensure Redis is running in the same AZ or datacenter as Sidekiq.
2023-02-01T04:40:32Z app[0100acd1] sin [info]If these values are close to 100,000, that means your Sidekiq process may be
2023-02-01T04:40:32Z app[0100acd1] sin [info]CPU-saturated; reduce your concurrency and/or see https://github.com/mperham/sidekiq/discussions/5039
The app[0100acd1] from the logs tells me that the workers and web processes aren’t deployed, which is why you’re not seeing the logs for these. If you deploy the application successfully you should see log file entries that look something like web[0100acd1] and worker[0100acd1].
I am still struggling with this. I’ve tried to create a new app that is super simple, added the sidekiq gem followed the instructions on Sidekiq Background Workers · Fly Docs, but I still get the same thing.
The strange thing is that the app deploys and runs OK.
My app has 2 allocations, but in the logs all I see is ‘app’
The allocations
The logs
2023-02-07T06:54:55.622 runner[313ca1ec] sin [info] Starting instance
2023-02-07T06:54:55.697 runner[313ca1ec] sin [info] Configuring virtual machine
2023-02-07T06:54:55.700 runner[313ca1ec] sin [info] Pulling container image
2023-02-07T06:54:56.092 runner[aafd77c2] sin [info] Starting instance
2023-02-07T06:54:56.168 runner[aafd77c2] sin [info] Configuring virtual machine
2023-02-07T06:54:56.169 runner[aafd77c2] sin [info] Pulling container image
2023-02-07T06:55:15.893 runner[313ca1ec] sin [info] Unpacking image
2023-02-07T06:55:15.914 runner[aafd77c2] sin [info] Unpacking image
2023-02-07T06:55:17.480 runner[313ca1ec] sin [info] Preparing kernel init
2023-02-07T06:55:17.481 runner[aafd77c2] sin [info] Preparing kernel init
2023-02-07T06:55:18.105 runner[aafd77c2] sin [info] Configuring firecracker
2023-02-07T06:55:18.108 runner[313ca1ec] sin [info] Configuring firecracker
2023-02-07T06:55:19.580 runner[aafd77c2] sin [info] Starting virtual machine
2023-02-07T06:55:19.582 runner[313ca1ec] sin [info] Starting virtual machine
2023-02-07T06:55:19.982 app[aafd77c2] sin [info] Starting init (commit: e3cff9e)...
2023-02-07T06:55:19.985 app[313ca1ec] sin [info] Starting init (commit: e3cff9e)...
2023-02-07T06:55:20.010 app[aafd77c2] sin [info] Preparing to run: `bin/rails fly:server` as root
2023-02-07T06:55:20.018 app[313ca1ec] sin [info] Preparing to run: `bundle exec sidekiq` as root
2023-02-07T06:55:20.039 app[aafd77c2] sin [info] 2023/02/07 06:55:20 listening on [fdaa:1:e40:a7b:80:aafd:77c2:2]:22 (DNS: [fdaa::3]:53)
2023-02-07T06:55:20.056 app[313ca1ec] sin [info] 2023/02/07 06:55:20 listening on [fdaa:1:e40:a7b:80:313c:a1ec:2]:22 (DNS: [fdaa::3]:53)
2023-02-07T06:55:22.430 app[aafd77c2] sin [info] fallocate -l 512M /swapfile
2023-02-07T06:55:22.443 app[aafd77c2] sin [info] chmod 0600 /swapfile
2023-02-07T06:55:22.448 app[aafd77c2] sin [info] mkswap /swapfile
2023-02-07T06:55:22.461 app[aafd77c2] sin [info] Setting up swapspace version 1, size = 512 MiB (536866816 bytes)
2023-02-07T06:55:22.461 app[aafd77c2] sin [info] no label, UUID=8f587903-bdbe-4f82-ac12-c0b4e1c3bdb2
2023-02-07T06:55:22.464 app[aafd77c2] sin [info] echo 10 > /proc/sys/vm/swappiness
2023-02-07T06:55:22.468 app[aafd77c2] sin [info] swapon /swapfile
2023-02-07T06:55:22.477 app[aafd77c2] sin [info] bin/rails server
2023-02-07T06:55:23.661 app[aafd77c2] sin [info] => Booting Puma
2023-02-07T06:55:23.661 app[aafd77c2] sin [info] => Rails 7.0.4 application starting in production
2023-02-07T06:55:23.661 app[aafd77c2] sin [info] => Run `bin/rails server --help` for more startup options
2023-02-07T06:55:26.429 app[313ca1ec] sin [info] 2023-02-07T06:55:26.420Z pid=520 tid=3x4 INFO: Booted Rails 7.0.4 application in production environment
2023-02-07T06:55:26.437 app[313ca1ec] sin [info] 2023-02-07T06:55:26.436Z pid=520 tid=3x4 INFO: Running in ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) +jemalloc [x86_64-linux]
2023-02-07T06:55:26.437 app[313ca1ec] sin [info] 2023-02-07T06:55:26.437Z pid=520 tid=3x4 INFO: See LICENSE and the LGPL-3.0 for licensing details.
2023-02-07T06:55:26.437 app[313ca1ec] sin [info] 2023-02-07T06:55:26.437Z pid=520 tid=3x4 INFO: Upgrade to Sidekiq Pro for more features and support: https://sidekiq.org
2023-02-07T06:55:26.442 app[313ca1ec] sin [info] 2023-02-07T06:55:26.440Z pid=520 tid=3x4 INFO: Sidekiq 7.0.3 connecting to Redis with options {:size=>5, :pool_name=>"internal", :url=>"redis://default:REDACTED@eu2-wired-weasel-30711.upstash.io:30711"}
2023-02-07T06:55:27.041 app[313ca1ec] sin [info] 2023-02-07T06:55:27.039Z pid=520 tid=3x4 INFO: Sidekiq 7.0.3 connecting to Redis with options {:size=>5, :pool_name=>"default", :url=>"redis://default:REDACTED@eu2-wired-weasel-30711.upstash.io:30711"}
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] Puma starting in single mode...
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] * Puma version: 5.6.5 (ruby 3.1.2-p20) ("Birdie's Version")
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] * Min threads: 5
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] * Max threads: 5
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] * Environment: production
2023-02-07T06:55:27.674 app[aafd77c2] sin [info] * PID: 531
2023-02-07T06:55:27.681 app[aafd77c2] sin [info] * Listening on http://0.0.0.0:8080
2023-02-07T06:55:27.693 app[aafd77c2] sin [info] Use Ctrl-C to stop
2023-02-07T06:56:00.718 runner[96eca55a] sin [info] Shutting down virtual machine
2023-02-07T06:56:02.690 app[96eca55a] sin [info] Sending signal SIGINT to main child process w/ PID 521
2023-02-07T06:56:02.713 app[96eca55a] sin [info] rails aborted!
2023-02-07T06:56:02.715 app[96eca55a] sin [info] Interrupt:
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/file_utils.rb:54:in `system'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/file_utils.rb:54:in `sh'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/lib/tasks/fly.rake:21:in `block (2 levels) in <main>'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:160:in `invoke_task'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block (2 levels) in top_level'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `each'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block in top_level'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:125:in `run_with_threads'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:110:in `top_level'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/commands/rake/rake_command.rb:24:in `block (2 levels) in perform'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/commands/rake/rake_command.rb:24:in `block in perform'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/rake-13.0.6/lib/rake/rake_module.rb:59:in `with_application'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/commands/rake/rake_command.rb:18:in `perform'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/command.rb:51:in `invoke'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/railties-7.0.4/lib/rails/commands.rb:18:in `<main>'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require'
2023-02-07T06:56:02.718 app[96eca55a] sin [info] /app/vendor/bundle/ruby/3.1.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require'
2023-02-07T06:56:02.719 app[96eca55a] sin [info] Tasks: TOP => fly:server
2023-02-07T06:56:02.719 app[96eca55a] sin [info] (See full trace by running task with --trace)
2023-02-07T06:56:03.964 app[96eca55a] sin [info] Starting clean up.
2023-02-07T06:56:09.332 app[313ca1ec] sin [info] 2023-02-07T06:56:09.328Z pid=520 tid=1uhc WARN: Your Redis network connection is performing extremely poorly.
2023-02-07T06:56:09.332 app[313ca1ec] sin [info] Last RTT readings were [160828, 160537, 160436, 160682, 160538], ideally these should be < 1000.
2023-02-07T06:56:09.332 app[313ca1ec] sin [info] Ensure Redis is running in the same AZ or datacenter as Sidekiq.
2023-02-07T06:56:09.332 app[313ca1ec] sin [info] If these values are close to 100,000, that means your Sidekiq process may be
2023-02-07T06:56:09.332 app[313ca1ec] sin [info] CPU-saturated; reduce your concurrency and/or see https://github.com/mperham/sidekiq/discussions/5039
2023-02-07T06:57:01.748 app[313ca1ec] sin [info] 2023-02-07T06:57:01.746Z pid=520 tid=1uhc WARN: Your Redis network connection is performing extremely poorly.
2023-02-07T06:57:01.748 app[313ca1ec] sin [info] Last RTT readings were [160452, 160406, 160754, 160602, 159646], ideally these should be < 1000.
2023-02-07T06:57:01.748 app[313ca1ec] sin [info] Ensure Redis is running in the same AZ or datacenter as Sidekiq.
2023-02-07T06:57:01.748 app[313ca1ec] sin [info] If these values are close to 100,000, that means your Sidekiq process may be
2023-02-07T06:57:01.748 app[313ca1ec] sin [info] CPU-saturated; reduce your concurrency and/or see https://github.com/mperham/sidekiq/discussions/5039
2023-02-07T06:57:54.159 app[313ca1ec] sin [info] 2023-02-07T06:57:54.158Z pid=520 tid=1uhc WARN: Your Redis network connection is performing extremely poorly.
2023-02-07T06:57:54.159 app[313ca1ec] sin [info] Last RTT readings were [159680, 160490, 160409, 160296, 160413], ideally these should be < 1000.
2023-02-07T06:57:54.159 app[313ca1ec] sin [info] Ensure Redis is running in the same AZ or datacenter as Sidekiq.
2023-02-07T06:57:54.159 app[313ca1ec] sin [info] If these values are close to 100,000, that means your Sidekiq process may be
2023-02-07T06:57:54.159 app[313ca1ec] sin [info] CPU-saturated; reduce your concurrency and/or see https://github.com/mperham/sidekiq/discussions/5039
I’m pretty new to docker/deployment stuff, so I don’t really know what I’m doing when I’m playing around in the docker and .toml file.