async icon indicating copy to clipboard operation
async copied to clipboard

NameError: uninitialized constant ApplicationRecord if having two subtask for DB query

Open zhongxiao37 opened this issue 2 years ago • 6 comments

Given that https://github.com/ged/ruby-pg/pull/397 is merged, I'm trying to use the async gem with latest ruby-pg in Rails 7. However, it seems that I could not use a database connection to two separated subtasks.

Here is the example:

Error log

Started GET "/async_db" for ::1 at 2022-03-15 23:37:05 +0800
  ActiveRecord::SchemaMigration Pluck (0.7ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
Processing by ApplicationController#async_db as HTML
  0.0s    error: Async::Task [oid=0x5ac8] [ec=0x5adc] [pid=45853] [2022-03-15 23:37:05 +0800]
               |   NameError: uninitialized constant ApplicationRecord
               |   Did you mean?  ApplicationJob
               |                  ApplicationHelper
               |   → app/models/user.rb:1 in `<main>'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27 in `require'
               |     app/controllers/application_controller.rb:30 in `block (2 levels) in async_db'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/async-1.30.1/lib/async/task.rb:260 in `block in make_fiber'
["DEBUGGER Exception: /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:986",
 #<RuntimeError: running is given, but running>,
 ["/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:115:in `set_mode'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:698:in `wait_next_action_'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:676:in `wait_next_action'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:201:in `wait_reply'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:205:in `on_load'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/session.rb:118:in `block in initialize'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27:in `require'",
  "/Users/pzhong/Documents/github/rails7/app/models/post.rb:1:in `<main>'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27:in `require'",
  "/Users/pzhong/Documents/github/rails7/app/controllers/application_controller.rb:26:in `block (2 levels) in async_db'",
  "/Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/async-1.30.1/lib/async/task.rb:260:in `block in make_fiber'"]]
 0.02s    error: Async::Task [oid=0x5af0] [ec=0x5b04] [pid=45853] [2022-03-15 23:37:05 +0800]
               |   RuntimeError: running is given, but running
               |   → /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:115 in `set_mode'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:698 in `wait_next_action_'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:676 in `wait_next_action'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:201 in `wait_reply'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/thread_client.rb:205 in `on_load'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/debug-1.4.0/lib/debug/session.rb:118 in `block in initialize'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27 in `require'
               |     app/models/post.rb:1 in `<main>'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/bootsnap-1.11.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30 in `require'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27 in `require'
               |     app/controllers/application_controller.rb:26 in `block (2 levels) in async_db'
               |     /Users/pzhong/.rbenv/versions/3.0.3/lib/ruby/gems/3.0.0/gems/async-1.30.1/lib/async/task.rb:260 in `block in make_fiber'
Completed 200 OK in 514ms (Views: 0.6ms | ActiveRecord: 0.0ms | Allocations: 6158)

app/models/post.rb

class Post < ApplicationRecord
end

app/models/user.rb

class User < ApplicationRecord
end

app/controllers/application_controller.rb

class ApplicationController < ActionController::Base
  def async_db
    users = []
    posts = []
    task = Async do |t|
      t.async do
        sleep(0.5)
      end

      t.async do
        posts << Post.find_by(user_id: rand(1..1000000))
      end

      t.async do
        users << User.find_by(id: rand(1..1000000))
      end
    end

    task.wait
    render json: { users: users.map(&:name), posts: posts.map(&:title) }
  end
end

Gemfile

source "https://rubygems.org"
git_source(:github) { |repo| "https://github.com/#{repo}.git" }

ruby "3.0.3"

# Bundle edge Rails instead: gem "rails", github: "rails/rails", branch: "main"
gem "rails", "~> 7.0.2.2"

# The original asset pipeline for Rails [https://github.com/rails/sprockets-rails]
gem "sprockets-rails", ">= 3.4.1"

# Use sqlite3 as the database for Active Record
gem "pg"

# Use the Puma web server [https://github.com/puma/puma]
gem "puma", "~> 5.0"

# Use JavaScript with ESM import maps [https://github.com/rails/importmap-rails]
gem "importmap-rails", ">= 0.9.2"

# Hotwire's SPA-like page accelerator [https://turbo.hotwired.dev]
gem "turbo-rails", ">= 0.9.0"

# Hotwire's modest JavaScript framework [https://stimulus.hotwired.dev]
gem "stimulus-rails", ">= 0.7.3"

# Build JSON APIs with ease [https://github.com/rails/jbuilder]
gem "jbuilder", "~> 2.11"

# Use Redis adapter to run Action Cable in production
gem "redis", "~> 4.0"

# Use Kredis to get higher-level data types in Redis [https://github.com/rails/kredis]
# gem "kredis"

# Use Active Model has_secure_password [https://guides.rubyonrails.org/active_model_basics.html#securepassword]
# gem "bcrypt", "~> 3.1.7"

# Windows does not include zoneinfo files, so bundle the tzinfo-data gem
gem "tzinfo-data", platforms: %i[ mingw mswin x64_mingw jruby ]

# Reduces boot times through caching; required in config/boot.rb
gem "bootsnap", ">= 1.4.4", require: false
gem 'slim'
gem "async", "~> 1.30"

# Use Sass to process CSS
# gem "sassc-rails", "~> 2.1"

# Use Active Storage variants [https://guides.rubyonrails.org/active_storage_overview.html#transforming-images]
# gem "image_processing", "~> 1.2"

group :development, :test do
  # See https://edgeguides.rubyonrails.org/debugging_rails_applications.html#debugging-with-the-debug-gem
  gem "debug", ">= 1.0.0", platforms: %i[ mri mingw x64_mingw ]
  gem 'debase'
  gem 'rubocop-rails'
  gem 'ruby-debug-ide'
end

group :development do
  # Use console on exceptions pages [https://github.com/rails/web-console]
  gem "web-console", ">= 4.1.0"

  # Add speed badges [https://github.com/MiniProfiler/rack-mini-profiler]
  # gem "rack-mini-profiler", ">= 2.3.3"

  # Speed up commands on slow machines / big apps [https://github.com/rails/spring]
  # gem "spring"
end

group :test do
  # Use system testing [https://guides.rubyonrails.org/testing.html#system-testing]
  gem "capybara", ">= 3.26"
  gem "selenium-webdriver", ">= 4.0.0"
  gem "webdrivers"
end

Gemfile.lock

GEM
  remote: https://rubygems.org/
  specs:
    actioncable (7.0.2.2)
      actionpack (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      nio4r (~> 2.0)
      websocket-driver (>= 0.6.1)
    actionmailbox (7.0.2.2)
      actionpack (= 7.0.2.2)
      activejob (= 7.0.2.2)
      activerecord (= 7.0.2.2)
      activestorage (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      mail (>= 2.7.1)
      net-imap
      net-pop
      net-smtp
    actionmailer (7.0.2.2)
      actionpack (= 7.0.2.2)
      actionview (= 7.0.2.2)
      activejob (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      mail (~> 2.5, >= 2.5.4)
      net-imap
      net-pop
      net-smtp
      rails-dom-testing (~> 2.0)
    actionpack (7.0.2.2)
      actionview (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      rack (~> 2.0, >= 2.2.0)
      rack-test (>= 0.6.3)
      rails-dom-testing (~> 2.0)
      rails-html-sanitizer (~> 1.0, >= 1.2.0)
    actiontext (7.0.2.2)
      actionpack (= 7.0.2.2)
      activerecord (= 7.0.2.2)
      activestorage (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      globalid (>= 0.6.0)
      nokogiri (>= 1.8.5)
    actionview (7.0.2.2)
      activesupport (= 7.0.2.2)
      builder (~> 3.1)
      erubi (~> 1.4)
      rails-dom-testing (~> 2.0)
      rails-html-sanitizer (~> 1.1, >= 1.2.0)
    activejob (7.0.2.2)
      activesupport (= 7.0.2.2)
      globalid (>= 0.3.6)
    activemodel (7.0.2.2)
      activesupport (= 7.0.2.2)
    activerecord (7.0.2.2)
      activemodel (= 7.0.2.2)
      activesupport (= 7.0.2.2)
    activestorage (7.0.2.2)
      actionpack (= 7.0.2.2)
      activejob (= 7.0.2.2)
      activerecord (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      marcel (~> 1.0)
      mini_mime (>= 1.1.0)
    activesupport (7.0.2.2)
      concurrent-ruby (~> 1.0, >= 1.0.2)
      i18n (>= 1.6, < 2)
      minitest (>= 5.1)
      tzinfo (~> 2.0)
    addressable (2.8.0)
      public_suffix (>= 2.0.2, < 5.0)
    ast (2.4.2)
    async (1.30.1)
      console (~> 1.10)
      nio4r (~> 2.3)
      timers (~> 4.1)
    bindex (0.8.1)
    bootsnap (1.11.1)
      msgpack (~> 1.2)
    builder (3.2.4)
    capybara (3.36.0)
      addressable
      matrix
      mini_mime (>= 0.1.3)
      nokogiri (~> 1.8)
      rack (>= 1.6.0)
      rack-test (>= 0.6.3)
      regexp_parser (>= 1.5, < 3.0)
      xpath (~> 3.2)
    childprocess (4.1.0)
    concurrent-ruby (1.1.9)
    console (1.14.0)
      fiber-local
    crass (1.0.6)
    debase (0.2.4.1)
      debase-ruby_core_source (>= 0.10.2)
    debase-ruby_core_source (0.10.14)
    debug (1.4.0)
      irb (>= 1.3.6)
      reline (>= 0.2.7)
    digest (3.1.0)
    erubi (1.10.0)
    fiber-local (1.0.0)
    globalid (1.0.0)
      activesupport (>= 5.0)
    i18n (1.10.0)
      concurrent-ruby (~> 1.0)
    importmap-rails (1.0.3)
      actionpack (>= 6.0.0)
      railties (>= 6.0.0)
    io-console (0.5.11)
    io-wait (0.2.1)
    irb (1.4.1)
      reline (>= 0.3.0)
    jbuilder (2.11.5)
      actionview (>= 5.0.0)
      activesupport (>= 5.0.0)
    loofah (2.14.0)
      crass (~> 1.0.2)
      nokogiri (>= 1.5.9)
    mail (2.7.1)
      mini_mime (>= 0.1.1)
    marcel (1.0.2)
    matrix (0.4.2)
    method_source (1.0.0)
    mini_mime (1.1.2)
    minitest (5.15.0)
    msgpack (1.4.5)
    net-imap (0.2.3)
      digest
      net-protocol
      strscan
    net-pop (0.1.1)
      digest
      net-protocol
      timeout
    net-protocol (0.1.2)
      io-wait
      timeout
    net-smtp (0.3.1)
      digest
      net-protocol
      timeout
    nio4r (2.5.8)
    nokogiri (1.13.3-x86_64-darwin)
      racc (~> 1.4)
    parallel (1.21.0)
    parser (3.1.1.0)
      ast (~> 2.4.1)
    pg (1.3.4)
    public_suffix (4.0.6)
    puma (5.6.2)
      nio4r (~> 2.0)
    racc (1.6.0)
    rack (2.2.3)
    rack-test (1.1.0)
      rack (>= 1.0, < 3)
    rails (7.0.2.2)
      actioncable (= 7.0.2.2)
      actionmailbox (= 7.0.2.2)
      actionmailer (= 7.0.2.2)
      actionpack (= 7.0.2.2)
      actiontext (= 7.0.2.2)
      actionview (= 7.0.2.2)
      activejob (= 7.0.2.2)
      activemodel (= 7.0.2.2)
      activerecord (= 7.0.2.2)
      activestorage (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      bundler (>= 1.15.0)
      railties (= 7.0.2.2)
    rails-dom-testing (2.0.3)
      activesupport (>= 4.2.0)
      nokogiri (>= 1.6)
    rails-html-sanitizer (1.4.2)
      loofah (~> 2.3)
    railties (7.0.2.2)
      actionpack (= 7.0.2.2)
      activesupport (= 7.0.2.2)
      method_source
      rake (>= 12.2)
      thor (~> 1.0)
      zeitwerk (~> 2.5)
    rainbow (3.1.1)
    rake (13.0.6)
    redis (4.6.0)
    regexp_parser (2.2.1)
    reline (0.3.1)
      io-console (~> 0.5)
    rexml (3.2.5)
    rubocop (1.26.0)
      parallel (~> 1.10)
      parser (>= 3.1.0.0)
      rainbow (>= 2.2.2, < 4.0)
      regexp_parser (>= 1.8, < 3.0)
      rexml
      rubocop-ast (>= 1.16.0, < 2.0)
      ruby-progressbar (~> 1.7)
      unicode-display_width (>= 1.4.0, < 3.0)
    rubocop-ast (1.16.0)
      parser (>= 3.1.1.0)
    rubocop-rails (2.14.0)
      activesupport (>= 4.2.0)
      rack (>= 1.1)
      rubocop (>= 1.7.0, < 2.0)
    ruby-debug-ide (0.7.3)
      rake (>= 0.8.1)
    ruby-progressbar (1.11.0)
    rubyzip (2.3.2)
    selenium-webdriver (4.1.0)
      childprocess (>= 0.5, < 5.0)
      rexml (~> 3.2, >= 3.2.5)
      rubyzip (>= 1.2.2)
    slim (4.1.0)
      temple (>= 0.7.6, < 0.9)
      tilt (>= 2.0.6, < 2.1)
    sprockets (4.0.3)
      concurrent-ruby (~> 1.0)
      rack (> 1, < 3)
    sprockets-rails (3.4.2)
      actionpack (>= 5.2)
      activesupport (>= 5.2)
      sprockets (>= 3.0.0)
    stimulus-rails (1.0.4)
      railties (>= 6.0.0)
    strscan (3.0.1)
    temple (0.8.2)
    thor (1.2.1)
    tilt (2.0.10)
    timeout (0.2.0)
    timers (4.3.3)
    turbo-rails (1.0.1)
      actionpack (>= 6.0.0)
      railties (>= 6.0.0)
    tzinfo (2.0.4)
      concurrent-ruby (~> 1.0)
    unicode-display_width (2.1.0)
    web-console (4.2.0)
      actionview (>= 6.0.0)
      activemodel (>= 6.0.0)
      bindex (>= 0.4.0)
      railties (>= 6.0.0)
    webdrivers (5.0.0)
      nokogiri (~> 1.6)
      rubyzip (>= 1.3.0)
      selenium-webdriver (~> 4.0)
    websocket-driver (0.7.5)
      websocket-extensions (>= 0.1.0)
    websocket-extensions (0.1.5)
    xpath (3.2.0)
      nokogiri (~> 1.8)
    zeitwerk (2.5.4)

PLATFORMS
  x86_64-darwin-20

DEPENDENCIES
  async (~> 1.30)
  bootsnap (>= 1.4.4)
  capybara (>= 3.26)
  debase
  debug (>= 1.0.0)
  importmap-rails (>= 0.9.2)
  jbuilder (~> 2.11)
  pg
  puma (~> 5.0)
  rails (~> 7.0.2.2)
  redis (~> 4.0)
  rubocop-rails
  ruby-debug-ide
  selenium-webdriver (>= 4.0.0)
  slim
  sprockets-rails (>= 3.4.1)
  stimulus-rails (>= 0.7.3)
  turbo-rails (>= 0.9.0)
  tzinfo-data
  web-console (>= 4.1.0)
  webdrivers

RUBY VERSION
   ruby 3.0.3p157

BUNDLED WITH
   2.2.32

Notes

If I change them in one subtask, it will work well.

app/controllers/application_controller.rb

class ApplicationController < ActionController::Base

  def async_db
    users = []
    posts = []
    task = Async do |t|
      t.async do
        sleep(0.5)
      end

      t.async do
        posts << Post.find_by(user_id: rand(1..1000000))
        users << User.find_by(id: rand(1..1000000))
      end
    end

    task.wait
    render json: { users: users.map(&:name), posts: posts.map(&:title) }
  end
end

zhongxiao37 avatar Mar 15 '22 15:03 zhongxiao37

Do you think it's load issue? make something wrong with Zeitwerk. Can you try adding require 'application_record' or some variation of that before the db model uses it?

ioquatix avatar Mar 15 '22 16:03 ioquatix

Can you reproduce with the debug gem commented out?

fxn avatar Mar 24 '22 09:03 fxn

We also run across this issue with any class that we use in subtasks. Only on the first request, the second request will have the class loaded.

pbstriker38 avatar Apr 06 '22 23:04 pbstriker38

Commenting out the debug gem does appear to have solved it 👍

pbstriker38 avatar Apr 06 '22 23:04 pbstriker38

We have some issues with autoloading in Ruby 3.1.1 and I will try to back port a fix for Ruby 3.1.2 if possible. A solution is to disable autoloading where possible.

ioquatix avatar Apr 07 '22 00:04 ioquatix

I'm proposing a fix here https://github.com/ruby/ruby/pull/5788

ioquatix avatar Apr 11 '22 11:04 ioquatix

This bug is fixed and will be released in Ruby 3.2. Sorry about that and thanks for your patience. If you want to help further, please retry your test case with the latest async on Ruby head.

ioquatix avatar Oct 31 '22 07:10 ioquatix