Permalink
Browse files

trace autoloads, and document hints for troubleshooting

Closes #32885.
  • Loading branch information...
fxn committed Sep 7, 2018
1 parent c3e5695 commit c03bba4f1f03bad7dc034af555b7f2b329cf76f5
@@ -79,6 +79,12 @@ def self.unload_interlock
# to allow arbitrary constants to be marked for unloading.
mattr_accessor :explicitly_unloadable_constants, default: []
# The logger used when tracing autoloads.
mattr_accessor :logger
# If true, trace autoloads with +logger.debug+.
mattr_accessor :verbose, default: false
# The WatchStack keeps a stack of the modules being watched as files are
# loaded. If a file in the process of being loaded (parent.rb) triggers the
# load of another file (child.rb) the stack will ensure that child.rb
@@ -416,7 +422,7 @@ def loadable_constants_for_path(path, bases = autoload_paths)
# Search for a file in autoload_paths matching the provided suffix.
def search_for_file(path_suffix)
path_suffix = path_suffix.sub(/(\.rb)?$/, ".rb".freeze)
path_suffix += ".rb" unless path_suffix.ends_with?(".rb")
autoload_paths.each do |root|
path = File.join(root, path_suffix)
@@ -450,6 +456,7 @@ def autoload_module!(into, const_name, qualified_name, path_suffix)
return nil unless base_path = autoloadable_module?(path_suffix)
mod = Module.new
into.const_set const_name, mod
log("constant #{qualified_name} autoloaded (module autovivified from #{File.join(base_path, path_suffix)})")
autoloaded_constants << qualified_name unless autoload_once_paths.include?(base_path)
autoloaded_constants.uniq!
mod
@@ -491,7 +498,7 @@ def load_missing_constant(from_mod, const_name)
raise ArgumentError, "A copy of #{from_mod} has been removed from the module tree but is still active!"
end
qualified_name = qualified_name_for from_mod, const_name
qualified_name = qualified_name_for(from_mod, const_name)
path_suffix = qualified_name.underscore
file_path = search_for_file(path_suffix)
@@ -504,8 +511,13 @@ def load_missing_constant(from_mod, const_name)
raise "Circular dependency detected while autoloading constant #{qualified_name}"
else
require_or_load(expanded, qualified_name)
raise LoadError, "Unable to autoload constant #{qualified_name}, expected #{file_path} to define it" unless from_mod.const_defined?(const_name, false)
return from_mod.const_get(const_name)
if from_mod.const_defined?(const_name, false)
log("constant #{qualified_name} autoloaded from #{expanded}.rb")
return from_mod.const_get(const_name)
else
raise LoadError, "Unable to autoload constant #{qualified_name}, expected #{file_path} to define it"
end
end
elsif mod = autoload_module!(from_mod, const_name, qualified_name, path_suffix)
return mod
@@ -554,6 +566,7 @@ def load_missing_constant(from_mod, const_name)
# as the environment will be in an inconsistent state, e.g. other constants
# may have already been unloaded and not accessible.
def remove_unloadable_constants!
log("removing unloadable constants")
autoloaded_constants.each { |const| remove_constant const }
autoloaded_constants.clear
Reference.clear!
@@ -743,6 +756,10 @@ def remove_constant(const) #:nodoc:
# The constant is no longer reachable, just skip it.
end
end
def log(message)
logger.debug("autoloading: #{message}") if logger && verbose
end
end
end
@@ -1130,3 +1130,52 @@ def test_load_and_require_stay_private
ActiveSupport::Dependencies.hook!
end
end
class DependenciesLogging < ActiveSupport::TestCase
MESSAGE = "message"
def with_settings(logger, verbose)
original_logger = ActiveSupport::Dependencies.logger
original_verbose = ActiveSupport::Dependencies.verbose
ActiveSupport::Dependencies.logger = logger
ActiveSupport::Dependencies.verbose = verbose
yield
ensure
ActiveSupport::Dependencies.logger = original_logger
ActiveSupport::Dependencies.verbose = original_verbose
end
def fake_logger
Class.new do
def self.debug(message)
message
end
end
end
test "does not log if the logger is nil and verbose is false" do
with_settings(nil, false) do
assert_nil ActiveSupport::Dependencies.log(MESSAGE)
end
end
test "does not log if the logger is nil and verbose is true" do
with_settings(nil, true) do
assert_nil ActiveSupport::Dependencies.log(MESSAGE)
end
end
test "does not log if the logger is set and verbose is false" do
with_settings(fake_logger, false) do
assert_nil ActiveSupport::Dependencies.log(MESSAGE)
end
end
test "logs if the logger is set and verbose is true" do
with_settings(fake_logger, true) do
assert_equal "autoloading: #{MESSAGE}", ActiveSupport::Dependencies.log(MESSAGE)
end
end
end
@@ -1350,3 +1350,34 @@ With the [Spring](https://github.com/rails/spring) pre-loader (included with new
Occasionally you may need to explicitly eager_load by using `Rails
.application.eager_load!` in the setup of your tests -- this might occur if your [tests involve multithreading](https://stackoverflow.com/questions/25796409/in-rails-how-can-i-eager-load-all-code-before-a-specific-rspec-test).
## Troubleshooting
### Tracing Autoloads
Active Support is able to report constants as they are autoloaded. To enable these traces in a Rails application, put the following two lines in some initializer:
```ruby
ActiveSupport::Dependencies.logger = Rails.logger
ActiveSupport::Dependencies.verbose = true
```
### Where is a Given Autoload Triggered?
If constant `Foo` is being autoloaded, and you'd like to know where is that autoload coming from, just throw
```ruby
puts caller
```
at the top of `foo.rb` and inspect the printed stack trace.
### Which Constants Have Been Autoloaded?
At any given time,
```ruby
ActiveSupport::Dependencies.autoloaded_constants
```
has the collection of constants that have been autoloaded so far.

5 comments on commit c03bba4

@schneems

This comment has been minimized.

Show comment
Hide comment
@schneems

schneems Sep 7, 2018

Member

This commit breaks derailed benchmarks for me

TypeError: no implicit conversion of true into String
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:459:in `join'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:459:in `autoload_module!'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:522:in `load_missing_constant'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/active_support.rb:43:in `load_missing_constant'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:199:in `const_missing'
  /Users/rschneeman/Documents/projects/codetriage/app/controllers/users/after_signup_controller.rb:1:in `<main>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in `require'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in `block in require_with_bootsnap_lfi'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/loaded_features_index.rb:65:in `register'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:20:in `require_with_bootsnap_lfi'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:29:in `require'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/skylight-core-2.0.2/lib/skylight/core/probes.rb:119:in `require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:293:in `block in require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:259:in `load_dependency'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:293:in `require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:380:in `block in require_or_load'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:37:in `block in load_interlock'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies/interlock.rb:14:in `block in loading'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/concurrency/share_lock.rb:151:in `exclusive'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies/interlock.rb:13:in `loading'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:37:in `load_interlock'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:358:in `require_or_load'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:336:in `depend_on'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/active_support.rb:59:in `depend_on'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:250:in `require_dependency'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:478:in `block (2 levels) in eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:477:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:477:in `block in eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:475:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:475:in `eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:356:in `eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application/finisher.rb:69:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application/finisher.rb:69:in `block in <module:Finisher>'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:32:in `instance_exec'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:32:in `run'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:61:in `block in run_initializers'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:228:in `block in tsort_each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:431:in `each_strongly_connected_component_from'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:349:in `block in each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `call'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:226:in `tsort_each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:205:in `tsort_each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:60:in `run_initializers'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application.rb:362:in `initialize!'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/lib/derailed_benchmarks/tasks.rb:26:in `block (2 levels) in <top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `block in execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:213:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:182:in `invoke'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/lib/derailed_benchmarks/tasks.rb:60:in `block (2 levels) in <top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `block in execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:213:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:237:in `block in invoke_prerequisites'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:235:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:235:in `invoke_prerequisites'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:212:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:182:in `invoke'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/bin/derailed:41:in `exec'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/command.rb:27:in `run'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/invocation.rb:126:in `invoke_command'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor.rb:369:in `dispatch'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/base.rb:444:in `start'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/bin/derailed:92:in `<top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/bin/derailed:23:in `load'
  /Users/rschneeman/.gem/ruby/2.5.1/bin/derailed:23:in `<top (required)>'
Member

schneems replied Sep 7, 2018

This commit breaks derailed benchmarks for me

TypeError: no implicit conversion of true into String
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:459:in `join'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:459:in `autoload_module!'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:522:in `load_missing_constant'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/active_support.rb:43:in `load_missing_constant'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:199:in `const_missing'
  /Users/rschneeman/Documents/projects/codetriage/app/controllers/users/after_signup_controller.rb:1:in `<main>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in `require'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in `block in require_with_bootsnap_lfi'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/loaded_features_index.rb:65:in `register'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:20:in `require_with_bootsnap_lfi'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:29:in `require'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/skylight-core-2.0.2/lib/skylight/core/probes.rb:119:in `require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:293:in `block in require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:259:in `load_dependency'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:293:in `require'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:380:in `block in require_or_load'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:37:in `block in load_interlock'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies/interlock.rb:14:in `block in loading'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/concurrency/share_lock.rb:151:in `exclusive'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies/interlock.rb:13:in `loading'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:37:in `load_interlock'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:358:in `require_or_load'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:336:in `depend_on'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/bootsnap-1.3.1/lib/bootsnap/load_path_cache/core_ext/active_support.rb:59:in `depend_on'
  /Users/rschneeman/Documents/projects/rails/activesupport/lib/active_support/dependencies.rb:250:in `require_dependency'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:478:in `block (2 levels) in eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:477:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:477:in `block in eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:475:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:475:in `eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/engine.rb:356:in `eager_load!'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application/finisher.rb:69:in `each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application/finisher.rb:69:in `block in <module:Finisher>'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:32:in `instance_exec'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:32:in `run'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:61:in `block in run_initializers'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:228:in `block in tsort_each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:431:in `each_strongly_connected_component_from'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:349:in `block in each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `call'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:347:in `each_strongly_connected_component'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:226:in `tsort_each'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/tsort.rb:205:in `tsort_each'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/initializable.rb:60:in `run_initializers'
  /Users/rschneeman/Documents/projects/rails/railties/lib/rails/application.rb:362:in `initialize!'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/lib/derailed_benchmarks/tasks.rb:26:in `block (2 levels) in <top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `block in execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:213:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:182:in `invoke'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/lib/derailed_benchmarks/tasks.rb:60:in `block (2 levels) in <top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `block in execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:271:in `execute'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:213:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:237:in `block in invoke_prerequisites'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:235:in `each'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:235:in `invoke_prerequisites'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:212:in `block in invoke_with_call_chain'
  /Users/rschneeman/.rubies/ruby-2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:193:in `invoke_with_call_chain'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/rake-12.3.1/lib/rake/task.rb:182:in `invoke'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/bin/derailed:41:in `exec'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/command.rb:27:in `run'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/invocation.rb:126:in `invoke_command'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor.rb:369:in `dispatch'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/thor-0.19.4/lib/thor/base.rb:444:in `start'
  /Users/rschneeman/.gem/ruby/2.5.1/gems/derailed_benchmarks-1.3.3/bin/derailed:92:in `<top (required)>'
  /Users/rschneeman/.gem/ruby/2.5.1/bin/derailed:23:in `load'
  /Users/rschneeman/.gem/ruby/2.5.1/bin/derailed:23:in `<top (required)>'
@schneems

This comment has been minimized.

Show comment
Hide comment
@schneems

schneems Sep 7, 2018

Member

the base_path here can be true

log("constant #{qualified_name} autoloaded (module autovivified from #{File.join(base_path, path_suffix)})")
Member

schneems replied Sep 7, 2018

the base_path here can be true

log("constant #{qualified_name} autoloaded (module autovivified from #{File.join(base_path, path_suffix)})")
@fxn

This comment has been minimized.

Show comment
Hide comment
@fxn

fxn Sep 8, 2018

Member

Hi @schneems! Thanks very much for reporting this.

It is very suspicious that something called base_path is not a string if true. Furthermore, that value comes from the predicate autoloadable_module?, which returns either a member of autoload_paths or nil.

I suspect bootsnap may be involved, how can I reproduce the error?

Member

fxn replied Sep 8, 2018

Hi @schneems! Thanks very much for reporting this.

It is very suspicious that something called base_path is not a string if true. Furthermore, that value comes from the predicate autoloadable_module?, which returns either a member of autoload_paths or nil.

I suspect bootsnap may be involved, how can I reproduce the error?

@fxn

This comment has been minimized.

Show comment
Hide comment
@fxn

fxn Sep 8, 2018

Member

Nevermind, I reproduced adding bootsnap to a hello world Rails app.

Member

fxn replied Sep 8, 2018

Nevermind, I reproduced adding bootsnap to a hello world Rails app.

@fxn

This comment has been minimized.

Show comment
Hide comment
@fxn

fxn Sep 8, 2018

Member

Discussion started in Shopify/bootsnap#197.

Member

fxn replied Sep 8, 2018

Discussion started in Shopify/bootsnap#197.

Please sign in to comment.