diff --git a/activesupport/lib/active_support/dependencies.rb b/activesupport/lib/active_support/dependencies.rb index 9dc2c46880..238a9f0ee6 100644 --- a/activesupport/lib/active_support/dependencies.rb +++ b/activesupport/lib/active_support/dependencies.rb @@ -79,6 +79,12 @@ module ActiveSupport #:nodoc: # 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 @@ module ActiveSupport #:nodoc: # 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 @@ module ActiveSupport #:nodoc: 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 @@ module ActiveSupport #:nodoc: 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 @@ module ActiveSupport #:nodoc: 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 @@ module ActiveSupport #:nodoc: # 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 @@ module ActiveSupport #: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 diff --git a/activesupport/test/dependencies_test.rb b/activesupport/test/dependencies_test.rb index 84cb64a7c2..a486ef5eac 100644 --- a/activesupport/test/dependencies_test.rb +++ b/activesupport/test/dependencies_test.rb @@ -1130,3 +1130,52 @@ class DependenciesTest < ActiveSupport::TestCase 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 diff --git a/guides/source/autoloading_and_reloading_constants.md b/guides/source/autoloading_and_reloading_constants.md index 6298651e4a..b3f923a017 100644 --- a/guides/source/autoloading_and_reloading_constants.md +++ b/guides/source/autoloading_and_reloading_constants.md @@ -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.