search

zombocom / derailed_benchmarks

Go faster, off the Rails - Benchmarks for your whole Rails app
2.96k stars 141 forks source link

Fix infinite loop when Zeitwerk is enabled #170

Closed engwan closed 4 years ago

engwan commented 4 years ago

@schneems I was having trouble running perf:mem when Zeitwerk is enabled.

I'm getting an infinite loop on the require because Zeitwerk also patches require:

/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:21:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb:23:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:21:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb:23:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:21:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb:23:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:21:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb:23:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:21:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb:23:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:84:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:28:in `require_relative'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk.rb:11:in `<module:Zeitwerk>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk.rb:3:in `<top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:76:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:76:in `block (2 levels) in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:58:in `measure_memory_impact'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:72:in `block in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:84:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/railties-6.0.2/lib/rails/application/configuration.rb:310:in `autoloader='
/builds/gitlab-org/gitlab/config/application.rb:34:in `<class:Application>'
/builds/gitlab-org/gitlab/config/application.rb:16:in `<module:Gitlab>'
/builds/gitlab-org/gitlab/config/application.rb:15:in `<top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:76:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:76:in `block (2 levels) in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:58:in `measure_memory_impact'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:72:in `block in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/core_ext/kernel_require.rb:84:in `require'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/load_tasks.rb:21:in `block (2 levels) in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `block in execute'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `each'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `execute'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:214:in `block in invoke_with_call_chain'
/usr/local/lib/ruby/2.6.0/monitor.rb:235:in `mon_synchronize'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:194:in `invoke_with_call_chain'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:183:in `invoke'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/lib/derailed_benchmarks/load_tasks.rb:62:in `block (2 levels) in <top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `block in execute'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `each'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:273:in `execute'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:214:in `block in invoke_with_call_chain'
/usr/local/lib/ruby/2.6.0/monitor.rb:235:in `mon_synchronize'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:194:in `invoke_with_call_chain'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:238:in `block in invoke_prerequisites'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:236:in `each'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:236:in `invoke_prerequisites'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:213:in `block in invoke_with_call_chain'
/usr/local/lib/ruby/2.6.0/monitor.rb:235:in `mon_synchronize'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:194:in `invoke_with_call_chain'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/rake-12.3.3/lib/rake/task.rb:183:in `invoke'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/bin/derailed:42:in `exec'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/thor-0.20.3/lib/thor/command.rb:27:in `run'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/thor-0.20.3/lib/thor/invocation.rb:126:in `invoke_command'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/thor-0.20.3/lib/thor.rb:387:in `dispatch'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/thor-0.20.3/lib/thor/base.rb:466:in `start'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/gems/derailed_benchmarks-1.6.0/bin/derailed:93:in `<top (required)>'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/bin/derailed:23:in `load'
/builds/gitlab-org/gitlab/vendor/ruby/2.6.0/bin/derailed:23:in `<top (required)>'

It seemed to be related to how we override require. See:

From: /home/engwan/.asdf/installs/ruby/2.6.5/lib/ruby/gems/2.6.0/gems/zeitwerk-2.2.2/lib/zeitwerk/kernel.rb @ line 16 :

    11:   # already existing ancestor chains.
    12:   alias_method :zeitwerk_original_require, :require
    13: 
    14:   # @param path [String]
    15:   # @return [Boolean]
 => 16:   def require(path)
    17:     if loader = Zeitwerk::Registry.loader_for(path)
    18:       if path.end_with?(".rb")
    19:         zeitwerk_original_require(path).tap do |required|
    20:           loader.on_file_autoloaded(path) if required
    21:         end

[3] pry(Kernel)> self.method(:require).source_location
=> ["/home/engwan/.asdf/installs/ruby/2.6.5/lib/ruby/gems/2.6.0/gems/derailed_benchmarks-1.4.2/lib/derailed_benchmarks/core_ext/kernel_require.rb", 71]
[4] pry(Kernel)> self.method(:zeitwerk_original_require).source_location
=> ["/home/engwan/.asdf/installs/ruby/2.6.5/lib/ruby/gems/2.6.0/gems/derailed_benchmarks-1.4.2/lib/derailed_benchmarks/core_ext/kernel_require.rb", 20]

This makes it very similar to how Zeitwerk / Bootsnap overrides require and this prevents the infinite loop.

What do you think of this change?

engwan commented 4 years ago

BTW, this is easy to reproduce with a new Rails 6 app.

  1. rails new sample
  2. Add derailed_benchmarks to the Gemfile
  3. Run bundle exec derailed exec perf:mem

The problem happens if either Zeitwerk or Bootsnap is enabled

engwan commented 4 years ago

I tried adding this so that we actually test with the default configuration:

diff --git a/test/rails_app/config/application.rb b/test/rails_app/config/application.rb
index 236dac5..b58f9e6 100644
--- a/test/rails_app/config/application.rb
+++ b/test/rails_app/config/application.rb
@@ -13,6 +13,8 @@ require 'devise'

 module Dummy
   class Application < Rails::Application
+    config.load_defaults Rails.version.to_f
+
     config.action_mailer.default_url_options = { host: 'localhost:3000' }

     # Settings in config/environments/* take precedence over those specified here.

But it doesn't make the test fail 🤔

I see the test is doing result = `cd '#{rails_app_path}' && #{cmd}`. I tried stepping through the code and it works when run here.

But if I manually cd to the test rails app and do bundle exec rake -f perf.rake perf:mem --trace I can reproduce the problem.

I'm not sure why it doesn't happen within the test.

engwan commented 4 years ago

I figured it out. We need Bundler.with_clean_env when running these rake tasks in tests because the surrounding bundler environment changes the way things are loaded and isn't really representative of running the rake task separately.

schneems commented 4 years ago

Thanks!

engwan commented 4 years ago

Thanks @schneems! Will you be doing a release soon?

schneems commented 4 years ago

It's already released in the latest version

On Tue, Mar 24, 2020 at 8:04 AM Heinrich Lee Yu notifications@github.com wrote:

Thanks @schneems https://github.com/schneems! Will you be doing a release soon?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/schneems/derailed_benchmarks/pull/170#issuecomment-603225802, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAOSYBLAYFGHBHR6FPAQM3RJCVUDANCNFSM4KZN5RZQ .

-- Richard Schneeman https://www.schneems.com he/him