collectiveidea / delayed_job

Database based asynchronous priority queue system -- Extracted from Shopify
http://groups.google.com/group/delayed_job
MIT License
4.82k stars 956 forks source link

IOError: closed stream error when starting worker process in Rails 6.1 on Ubuntu #1133

Closed timdown closed 2 months ago

timdown commented 3 years ago

Steps to reproduce:

  1. Use a machine running Ubuntu 20.04 with Ruby (I used 2.6.5 but I don't think it matters) and Bundler
  2. Create a new Rails 6.1 application
  3. Add gem 'daemons' and gem 'delayed_job_active_record' to Gemfile
  4. bundle install
  5. Generate the DJ table with bundle exec rails generate delayed_job:active_record then bundle exec rake db:migrate
  6. Start a worker process using bundle exec ruby bin/delayed_job start
  7. The worker starts but sometimes (not always, I think), the following error is reported in the console:
$ bundle exec ruby bin/delayed_job start
E, [2021-01-04T16:05:25.312502 #203830] ERROR -- : Exception rescued in listen-run_thread:
IOError: closed stream
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:317:in `select'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:317:in `readpartial'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:290:in `read_events'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:263:in `process'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:236:in `block in run'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:232:in `synchronize'
/home/tim/.rvm/gems/ruby-2.6.5/gems/rb-inotify-0.10.1/lib/rb-inotify/notifier.rb:232:in `run'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/adapter/linux.rb:41:in `_run'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/adapter/base.rb:79:in `block in start'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/thread.rb:26:in `rescue_and_log'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/thread.rb:18:in `block in new'
--- Thread.new ---
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/adapter/base.rb:75:in `start'
/usr/share/rvm/rubies/ruby-2.6.5/lib/ruby/2.6.0/forwardable.rb:230:in `start'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/listener.rb:71:in `block in <class:Listener>'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/fsm.rb:121:in `instance_eval'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/fsm.rb:121:in `call'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/fsm.rb:102:in `transition_with_callbacks!'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/fsm.rb:69:in `transition'
/home/tim/.rvm/gems/ruby-2.6.5/gems/listen-3.4.0/lib/listen/listener.rb:92:in `start'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/evented_file_update_checker.rb:109:in `start'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/evented_file_update_checker.rb:89:in `block in initialize'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/fork_tracker.rb:36:in `each'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/fork_tracker.rb:36:in `check!'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/fork_tracker.rb:14:in `fork'
/home/tim/.rvm/gems/ruby-2.6.5/gems/activesupport-6.1.0/lib/active_support/fork_tracker.rb:26:in `fork'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/daemonize.rb:10:in `safefork'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/daemonize.rb:67:in `call_as_daemon'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/application.rb:279:in `start_proc'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/application.rb:305:in `start'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/controller.rb:56:in `run'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons.rb:199:in `block in run_proc'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons/cmdline.rb:121:in `catch_exceptions'
/home/tim/.rvm/gems/ruby-2.6.5/gems/daemons-1.3.1/lib/daemons.rb:198:in `run_proc'
/home/tim/.rvm/gems/ruby-2.6.5/gems/delayed_job-4.1.9/lib/delayed/command.rb:123:in `run_process'
/home/tim/.rvm/gems/ruby-2.6.5/gems/delayed_job-4.1.9/lib/delayed/command.rb:104:in `block in daemonize'
/home/tim/.rvm/gems/ruby-2.6.5/gems/delayed_job-4.1.9/lib/delayed/command.rb:102:in `times'
/home/tim/.rvm/gems/ruby-2.6.5/gems/delayed_job-4.1.9/lib/delayed/command.rb:102:in `daemonize'
bin/delayed_job:5:in `<main>'
delayed_job: process with pid 203830 started.

This does not happen with DJ 4.1.9 in Rails 6.0.3.4. I've tried it on macOS and the error does not appear. I've also tried changing the Ruby version to 3.0.0 and the error still appears.

roboyeti commented 3 years ago

Same issue with Rails 6, all versions tried so far, after upgrading from 5. Possibly related to this issue: https://github.com/collectiveidea/delayed_job/issues/1099

joshfester commented 3 years ago

Same issue here. Happens in both development and production. Using the rake task (rake jobs:work) seems to work ok. But that's not ideal for production mode

soorajhealthplotter commented 3 years ago

I am also facing same issue. Sometimes the delayed job starts.but sometime it is throwing error in both production and development environment Ruby version: 2.6 Rails version: 6.1

marcoschicote commented 3 years ago

Same issue here

jminterwebs commented 2 years ago

Same issue

ajaybhayani741 commented 1 year ago

Hey @timdown @roboyeti @marcoschicote @joshfester @jminterwebs

Did anyone get the solution to this issue? I m suffering from the same issue.

joshfester commented 1 year ago

@ajaybhayani741 I ended up moving on to Sidekiq and it's been great. If that's a possibility for you, I would definitely recommend it

jminterwebs commented 1 year ago

@ajaybhayani741, Yes unfortunately I complete forgot how. I was also dealing with isolating the worker into its own docker container as well.

Taking a shot in the dark on this but what ENV are you running in? I would check the config/delayed_job.rb and make sure you are allowing the worker to run in the ENV/

ducpt1012 commented 1 year ago

Same issue when I use it in a transaction.

grasshopper1 commented 1 year ago

I believe it is closely related to the configuration option config.file_watcher = ActiveSupport::EventedFileUpdateChecker

But I have no solution other than to disable that configuration option.

Since the file_watcher is not active in production environment I do not see the problem occur in that environment.

Ruby version: 2.7.4p191 Rails version: 6.1.7.2 DJ version: 4.1.11 listen version: 3.8.0 daemons version: 1.4.1 rb-inotify version: 0.10.1 linux system: debian 11 (bullseye)

allenjgreer commented 1 year ago

For anyone still encountering this issue, I was able to identify the root issue with inspiration from this stackoverflow answer

When running the delayed job process in daemonized mode bundle exec ruby bin/delayed_job start

From current script generator:

!/usr/bin/env ruby

require File.expand_path(File.join(File.dirname(FILE), '..', 'config', 'environment')) require 'delayed/command' Delayed::Command.new(ARGV).daemonize

I too a look into the daemonize gem and found that when starting up, it actually CLOSES ALL IO STREAMS!!. Modifying global state is always fun 👍 .

Within the script file, it first boots Rails via loading config/environment and especially with the config option eager_load = true means that if there is any code during the bootup process that opens up IOs (e.g. I was opening up cache connections via the Dalli gem) will be closed after the call to daemonize.

My current workaround is to ensure that Rails is loaded AFTER daemonize

#!/usr/bin/env ruby

require "delayed_job"
require "delayed_job_active_record"
require "delayed/command"

module LoadRailsAfterRunProc
  def self.included base
    after_fork_method = base.method(:after_fork)
    base.define_singleton_method :after_fork do |*args|
      # after Daemons.run_proc method
      require File.expand_path(File.join(File.dirname(__FILE__), '..', 'config', 'environment'))
      after_fork_method.call(*args)
    end
  end
end

Delayed::Worker.include(LoadRailsAfterRunProc)
Delayed::Command.new(ARGV).daemonize

This explains also why running it via rake rake jobs:work does not have any issues as it does not daemonize the process.

factor4 commented 1 year ago

@allenjgreer Your workaround solved it here on macOS and FreeBSD. Thank you very much!

toncid commented 1 year ago

Hello! Any ideas why there is no trace of the error if delayed_job is started with an identifier (./bin/delayed_job -i 1234 start) as indicated in #1172?

albus522 commented 2 months ago

Closing stale

philayres commented 3 weeks ago

Hey @albus522 or other maintainers. How do we get the fix proposed by @allenjgreer incorporated in to the delayed_job startup script so it stop affecting new implementations, and update the README or some other upgrade notes for existing apps?

Is it supposed to go in lib/generators/delayed_job/templates/script? I've been fighting with this for ages. It definitely shouldn't be a closed issue in my opinion.

I'd be happy to contribute a PR, if it is likely to be accepted (in a reasonable timescale.)