Debugging a Bundler LoadError
I recently worked on fixing an interesting bug in Bundler which was breaking user’s tests. I thought this was a really interesting problem and would be insightful to other people on problems that Bundler handles beyond just managing dependencies.
For the past few months, users have been reporting a LoadError with Bundler when they run their test suite. The error message usually reads like:
load': cannot load such file -- /home/<user>/.rvm/rubies/ruby-2.0.0-p648/lib/ruby/gems/2.0.0/gems/bundler-1.16.2/exe/bundle (LoadError)This issue was affecting a small set of users that were installing their gems with bundle install --path and their test suite was executing bundle exec
Let’s take a look at the --path option first and break down what happens in your Ruby environment.
bundle install --path
When you specify the --path option in bundle install — Bundler will install your gems into a separate folder, also known as a gem repository. Typically people specify a folder that’s inside their application directory, like vendor/bundle, and the end result looks like this:
We now have 2 gem repositories, the default repository which holds the gems that we have installed via gem install , like Bundler. And the repository that Bundler installed your gems from the Gemfile into.
One thing to note about using the --path option is that the gems cannot be loaded or executed like a gem that has been installed with gem install. Here’s an example of trying to load and execute the RSpec gem that has been installed with a Gemfile using bundle install --path
$ ./vendor/bundle/ruby/2.5.0/bin/rspec
Traceback (most recent call last):
2: from ./vendor/bundle/ruby/2.5.0/bin/rspec:23:in `<main>'
1: from /Users/colby/.rubies/ruby-2.5.1/lib/ruby/2.5.0/rubygems.rb:308:in `activate_bin_path'
/Users/colby/.rubies/ruby-2.5.1/lib/ruby/2.5.0/rubygems.rb:289:in `find_spec_for_exe': can't find gem rspec-core (>= 0.a) with executable rspec (Gem::GemNotFoundException)$ irb
irb(main):001:0> require 'rspec'
Traceback (most recent call last):
4: from /Users/colby/.rubies/ruby-2.5.1/bin/irb:11:in `<main>'
3: from (irb):1
2: from /Users/colby/.rubies/ruby-2.5.1/lib/ruby/2.5.0/rubygems/core_ext/kernel_require.rb:59:in `require'
1: from /Users/colby/.rubies/ruby-2.5.1/lib/ruby/2.5.0/rubygems/core_ext/kernel_require.rb:59:in `require'
LoadError (cannot load such file -- rspec)
This error occurs because your Ruby environment doesn’t know about the gem repository at vendor/bundle, only Bundler does.
We can find out where the default gem repository is with:
$ ruby -e 'puts Gem.default_dir'
/Library/Ruby/Gems/2.3.0If we want to load the gems that we installed with Bundler, we can set a special environment variable called GEM_HOME to change the gem repository.
$ GEM_HOME=vendor/bundle/ruby/2.5.0 irb
irb(main):002:0> require 'rspec'
=> trueSetting the gem environment with GEM_HOME every time we wanted to load a gem would be a big pain. Luckily Bundler has an awesome command called bundle exec to do this for us.
bundle exec
The exec command is a feature in Bundler that will automatically setup the Ruby environment and execute the given command. Using the previous example, we can load RSpec with:
$ bundle exec irb
irb(main):001:0> require 'rspec'
=> trueI recommend checking out the Bundler documentation on bundle exec if you want to learn more.
Nested bundle exec
The next part to get this error is that a test is executing bundle exec inside bundle exec <test suite>. That may sound surprising, but running bundle exec inside bundle exec is nothing out of the ordinary and is supported by Bundler. There are use cases where a test suite may depend on a gem being executed.
Here’s an example to show how this works
Looking back at the issue on Github, what the error message is telling us is that the test that is executing the bundle exec command cannot load Bundler correctly.
Lets reproduce this problem
Note: I’m using the chruby tool to manage my versions of Ruby. All paths to Bundler/Gems/Ruby will vary depending on your environment.
Let’s start diving into some code and start debugging Bunder’s behavior. The first thing we’ll look at is a sample reproduction that was posted by Thbar on Github.
We’ll clone the repository and see if we can reproduce the error. I’m going to be using Ruby 2.5.1 and the latest version of RubyGems and Bundler, which is currently v2.7.7 and v1.16.4.
$ git clone https://github.com/thbar/repro-bundler-issue-6537
Cloning into 'repro-bundler-issue-6537'...
remote: Counting objects: 22, done.
remote: Total 22 (delta 0), reused 0 (delta 0), pack-reused 22
Unpacking objects: 100% (22/22), done.$ cd repro-bundler-issue-6537$ bundle install --path vendor/bundle
Fetching gem metadata from https://rubygems.org/..........
Using bundler 1.16.4
Fetching diff-lcs 1.3
Installing diff-lcs 1.3
Fetching rspec-support 3.7.1
Installing rspec-support 3.7.1
Fetching rspec-core 3.7.1
Installing rspec-core 3.7.1
Fetching rspec-expectations 3.7.0
Installing rspec-expectations 3.7.0
Fetching rspec-mocks 3.7.0
Installing rspec-mocks 3.7.0
Fetching rspec 3.7.0
Installing rspec 3.7.0
Bundle complete! 1 Gemfile dependency, 7 gems now installed.
Bundled gems are installed into `./vendor/bundle`$ bundle exec rspec
Traceback (most recent call last):
1: from /Users/colby/.gem/ruby/2.5.1/bin/bundle:23:in `<main>'
/Users/colby/.gem/ruby/2.5.1/bin/bundle:23:in `load': cannot load such file -- /Users/colby/.rubies/ruby-2.5.1/lib/ruby/gems/2.5.0/gems/bundler-1.16.4/exe/bundle (LoadError)
FFailures:1) Some spec works
Failure/Error: expect(output).to include('Bundler')
expected "" to include "Bundler"
# ./spec/sample_spec.rb:4:in `block (2 levels) in <top (required)>'Finished in 0.25106 seconds (files took 0.11008 seconds to load)
1 example, 1 failure
Awesome! 🎉 We were able to replicate the issue on a local machine.
Looking at the error from running the test, we can see that the binstub is trying to load the Bundle executable file at:
/Users/colby/.rubies/ruby-2.5.1/lib/ruby/gems/2.5.0/gems/bundler-1.16.4/exe/bundleThis file obviously doesn’t exist. We can find out where the bundle executable file actually is located using RubyGems:
$ irb
irb(main):001:0> Gem.bin_path("bundler", "bundle", "1.16.4")
=> "/Users/colby/.gem/ruby/2.5.1/gems/bundler-1.16.4/exe/bundle"What’s interesting about the path in the error message is that it’s also the path that contains Ruby’s default gems.
$ ls /Users/colby/.rubies/ruby-2.5.1/lib/ruby/gems/2.5.0/gems/
bundler-1.16.2/ minitest-5.10.3/ power_assert-1.1.1/ rdoc-6.0.1/ xmlrpc-0.3.0/ did_you_mean-1.2.0/ net-telnet-0.1.1/ rake-12.3.0/ test-unit-3.2.7/If you’re not familiar with the default gems. Ruby ships with a set of gems such as Rake, which provides the rake command. You may also notice another particular gem in that list as well.
Wait… is Bundler in the default gems!?
Yes it is! That’s a full copy of Bundler (note that it’s an older version) that RubyGems installs when you run gem update --system. If you didn’t already know, there are plans for RubyGems and Bundler to be merged together. As a result RubyGems has started depending on particular functionality in Bundler. Note that this is not the same copy of Bundler that gets installed with gem install bundler, even if they’re the same version.
To review what we have learned so far. Only users that are running bundle install with the --path option, and have specs which are executing bundle exec are running into this LoadError. Finally, the path to the Bundle executable that Ruby is trying to load is the same path that holds Ruby’s default gems. But they’re 2 different versions of Bundler (1.16.2 and 1.16.4).
Let’s start debugging and see what we can learn.
Diving into Bundler
Let’s start debugging what bundle exec does to the Ruby environment. I’m going to change the test to print the current state of the ENV and filter out just the Ruby, RubyGems and Bundler related vars.
1 │ RSpec.describe "Some spec" do
2 │ it "works" do
3 │ require 'pp'
4 │ pp ENV.select { |k,_| k =~ /GEM|BUNDLE|RUBY/ }
5 │ # output = `bundle --version`
6 │ # expect(output).to include('Bundler')
7 │ end
8 │ endThere will be quite a number of lines printed out but what I’m mainly focused on are these particular variables.
"GEM_HOME"=>
"/Users/colby/Projects/repro-bundler-issue-6537/vendor/bundle/ruby/2.5.0",
"GEM_HOME"=>"","BUNDLE_BIN_PATH"=>"/Users/colby/.gem/ruby/2.5.1/gems/bundler-1.16.4/exe/bundle",
"RUBYLIB"=>"/Users/colby/.gem/ruby/2.5.1/gems/bundler-1.16.4/lib",
"BUNDLE_GEMFILE"=>"/Users/colby/Projects/repro-bundler-issue-6537/Gemfile",
"BUNDLER_VERSION"=>"1.16.4",
"RUBYOPT"=>"-rbundler/setup"
You’ll see the GEM_HOME variable that i talked about before and some other ENV vars relating to Bundler and Ruby. A couple of interesting variables that Bundler is setting though is RUBYOPT and RUBYLIB. This will have Ruby immediately load Blunder located at /Users/colby/.gem/ruby/2.5.1/gems/bundler-1.16.4/lib when our test executes bundle exec again (or anything that loads Ruby).
We can test this by running a quick script that checks what the version constant for Bundler is.
1 │ RSpec.describe "Some spec" do
2 │ it "works" do
3 │ puts `ruby -e "puts Bundler::VERSION"`
4 │ # output = `bundle --version`
5 │ # expect(output).to include('Bundler')
6 │ end
7 │ end$ bundle exec rspec
1.16.4
Bundler does this because it needs to setup the Ruby environment with all the gems in your Gemfile before your script can run, otherwise you won’t have the gems from your Gemfile available.
So far nothing unusual has showed up to suggest a problem. Let’s keep going and see what else we can find.
The line in the bundle binstub that is being executed when we run bundle exec in our test suit is this.
load Gem.activate_bin_path('bundler', 'bundle', version)Gem.activate_bin_path will return the incorrect path that we see in our error, but what’s interesting about this is method is that it’s defined in Bundler, not RubyGems.
1 │ RSpec.describe "Some spec" do
2 │ it "works" do
3 │ puts `ruby -e "puts Gem.method(:activate_bin_path).source_location"`
4 │ # output = `bundle --version`
5 │ # expect(output).to include('Bundler')
6 │ end
7 │ end$ bundle exec rspec
/Users/colby/.gem/ruby/2.5.1/gems/bundler-1.16.4/lib/bundler/rubygems_integration.rb
476
Let’s have a closer look at see what it does:
Ah! Bundler just returns the value of BUNDLE_BIN_PATH if the executable is bundle, otherwise Bundler will just build the path from the Gem’s gemspec.
Because the return value of Gem.activate_bin_path and the BUNDLE_BIN_PATH are different when we run bundle exec rspec means that Bundler is changing the value of BUNDLE_BIN_PATH somewhere. If I follow the execution path in bundler/setup, we’ll come across a line that looks like it might be doing just this.
# lib/bundler/runtime.rb19 │
20 │ specs = groups.any? ? @definition.specs_for(groups) : requested_specs
21 │
22 │ SharedHelpers.set_bundle_environment
23 │ Bundler.rubygems.replace_entrypoints(specs)
24 │
And If we open the method up and Bingo! We’re setting BUNDLE_BIN_PATH.
So Bundler is getting the bin_path from RubyGems (Note that Bundler.rubygems.bin_path just delegates to Gem.bin_path), so let’s dive into RubyGems then.
RubyGems is not doing anything special here. It just queries Bundler’s loaded gemspec to get the path to the bin file. Let’s start checking Bundler’s gemspec and ask RubyGems what data is has.
If I place some puts in Bundler’s source code and then run our spec again
# lib/bundler/shared_helpers.rb295 │ begin
296 │ puts "#" * 10
297 │ bundler = Gem.loaded_specs["bundler"]
298 │ puts "loaded from: #{bundler.loaded_from}"
299 │ puts "base path: #{bundler.base_dir}"
300 │ puts "#" * 10
301 │ Bundler::SharedHelpers.set_env "BUNDLE_BIN_PATH", Bundler.rubygems.bin_path("bundler", "bundle", VERSION)
302 │ rescue Gem::GemNotFoundException
303 │ Bundler::SharedHelpers.set_env "BUNDLE_BIN_PATH", File.expand_path("../../../exe/bundle", __FILE__)
304 │ end$ bundle exec rspec
##########
loaded from: /Users/colby/.rubies/ruby-2.5.1/lib/ruby/gems/2.5.0/specifications/default/bundler-1.16.2.gemspec
base path: /Users/colby/.rubies/ruby-2.5.1/lib/ruby/gems/2.5.0
##########
Ah ha! The gemspec for Bundler in our Ruby Environment is for the wrong version of Bundler, this is the gemspec file for the version of Bundler that RubyGems installed into our default gems!
When we ask what the bin_file for Bundler is, RubyGems will just take the gemspecs’s base_path and sticks gems/bundler-1.16.4/exe/bundle together which is what gives us the path that doesn’t exist.
Why is this happening?
Remember the RUBYOPT ENV var that Bundler sets? This instructs Ruby to load bundle/setup which in turn tells RubyGems to load and activate the Bundler gem. RubyGems will search through the list of installed gems specified by the GEM_HOME and GEM_PATH ENV vars (RubyGems will look through the default gem repository if those ENV vars are not set) and also look through the set of default gems.
It won’t find Bundler’s gemspec in GEM_HOME because Bundler changes GEM_HOME when the Gemfile is installed using the --path option in bundle install. And bundle exec sets the GEM_PATH ENV var to an empty string.
RubyGems will eventually find Bundler’s gemspec that’s inside Ruby’s default gems that RubyGems installed and then activate it.
Why is the version different
You may be wondering why the version is different if RubyGems is loading a different version of Bundler. Long story short, When Bundler is setting up the gem environment, it will create a new Bundler gemspec for itself and replace the one that’s already been loaded with that. The new gemspec’s version is whatever the Bundler::VERSION constant currently is.
If i install the same version of Bundler that RubyGems installs, does this problem go away?
Yes. 😆
I created a PR on Github to fix this issue which will be released in Bundler’s next release if you’re interested. I hope you enjoyed this post and let me know if you would like to see more posts like this.
You can also follow me Twitter at https://twitter.com/0xColby 👋
