Debugging Rails 5 autoloading

I was recently working on an app migration from Rails 4 to Rails 5. Among many other problems to resolve, at some point, you have to make sure autoloading and eager loading are working fine. Unfortunatelly in case of any issues it is not easy to track what is loaded and when as the logging support was removed from the ActiveSupport::Dependencies class in Rails 5.

Autoload logging for Rails 5

Good news is that it is still possible to generate some information that might be useful during troubleshooting. Here is a simple code that can be added as an initializer (config/initializers) to generate autoloading logs:

ActiveSupport::Dependencies.singleton_class.prepend(Module.new do
  def require_or_load (*args)
    Rails.logger.debug "#{__method__}(#{args.map(&:inspect).join(', ')})"
    super
  end
end)

Remember to restart the server to see the change.

If you do not run your server in background mode, you can replace Rails.logger.debug with puts to print the information to standard output.

Here is an example output. You can easily find which classes where loaded during the start and when.

test1 git:(master) ✗ rails s -b 0.0.0.0 -p 3005
=> Booting Puma
=> Rails 5.2.4.5 application starting in development
=> Run `rails server -h` for more startup options
/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/actionpack-5.2.4.5/lib/action_dispatch/middleware/stack.rb:37: warning: Using the last argument as keyword parameters is deprecated; maybe ** should be added to the call
/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/actionpack-5.2.4.5/lib/action_dispatch/middleware/static.rb:111: warning: The called method `initialize' is defined here
require_or_load("/home/paul/dev/test/rails52/test1/app/models/user", "User")
require_or_load("/home/paul/dev/test/rails52/test1/app/models/application_record", "ApplicationRecord")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/active_storage/base_controller.rb")
require_or_load("active_storage/base_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/active_storage/blobs_controller.rb")
require_or_load("active_storage/blobs_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/concerns/active_storage/set_blob", "ActiveStorage::SetBlob")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/active_storage/direct_uploads_controller.rb")
require_or_load("active_storage/direct_uploads_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/active_storage/disk_controller.rb")
require_or_load("active_storage/disk_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/active_storage/representations_controller.rb")
require_or_load("active_storage/representations_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/concerns/active_storage/set_blob.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/controllers/concerns/active_storage/set_blob.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/jobs/active_storage/analyze_job.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/jobs/active_storage/base_job", "ActiveStorage::BaseJob")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/jobs/active_storage/base_job.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/jobs/active_storage/purge_job.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/attachment.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/analyzable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/identifiable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/representable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/analyzable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/identifiable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/blob/representable.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/current.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/filename.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/filename/parameters.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/filename/parameters.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/preview.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/variant.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/activestorage-5.2.4.5/app/models/active_storage/variation.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/confirmations_controller.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise_controller", "DeviseController")
require_or_load("/home/paul/dev/test/rails52/test1/app/controllers/application_controller", "ApplicationController")
require_or_load("/home/paul/dev/test/rails52/test1/app/helpers/application_helper.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/helpers/application_helper.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/helpers/devise_helper.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/helpers/devise_helper.rb")
require_or_load("devise/confirmations_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/omniauth_callbacks_controller.rb")
require_or_load("devise/omniauth_callbacks_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/passwords_controller.rb")
require_or_load("devise/passwords_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/registrations_controller.rb")
require_or_load("devise/registrations_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/sessions_controller.rb")
require_or_load("devise/sessions_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise/unlocks_controller.rb")
require_or_load("devise/unlocks_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/controllers/devise_controller.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/helpers/devise_helper.rb")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-4.7.3/app/mailers/devise/mailer.rb")
require_or_load("devise/mailer_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-security-0.15.0/app/controllers/devise/paranoid_verification_code_controller.rb")
require_or_load("devise/paranoid_verification_code_helper")
require_or_load("/home/paul/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/devise-security-0.15.0/app/controllers/devise/password_expired_controller.rb")
require_or_load("devise/password_expired_helper")
require_or_load("/home/paul/dev/test/rails52/test1/app/channels/application_cable/channel.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/channels/application_cable/connection.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/controllers/application_controller.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/controllers/password_expired_controller.rb")
require_or_load("password_expired_helper")
require_or_load("/home/paul/dev/test/rails52/test1/app/helpers/application_helper.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/jobs/application_job.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/mailers/application_mailer.rb")
require_or_load("application_mailer_helper")
require_or_load("/home/paul/dev/test/rails52/test1/app/models/application_record.rb")
require_or_load("/home/paul/dev/test/rails52/test1/app/models/user.rb")
Puma starting in single mode...
* Version 3.12.6 (ruby 2.7.1-p83), codename: Llamas in Pajamas
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://0.0.0.0:3005
Use Ctrl-C to stop

Extra: Autoload logging in Rails 6

For Rails 6 there is an out of the box solution. The easiest way to enable logging is to add:

Rails.autoloaders.log!

to config/application.rb. That will print the logs to standard output.

For more information please check Rails autoloading guide.