BUNDLE_APP_CONFIG env var not available during bundler/setup run (RUBYOPT="-rbundler/setup")

[t-anjan]

I have asked this same question on SO too: https://stackoverflow.com/questions/51879025/starting-puma-w-o-bundle-exec-works-doesnt-work-with-bundle-exec-bundle-app . I haven't received any response yet. So, I am reproducing it here, hoping for more relevant eyes on it.

I have created a docker container with a Rails 5.2 app. The Dockerfile is here: https://pastebin.com/T1hjYtJ8 . The compose file is here: https://pastebin.com/VEJBT8ZK . They may not be strictly relevant to this question, but still I am giving links to the configs, just in case. It is a pretty standard Dockerfile and compose file.

The puma.rb used in the app is shown here: https://pastebin.com/ic9ig3bC .

When I create the container, puma is executed as bundle exec puma -C config/puma.rb. The puma process throws errors in the puma_error.log file:

/usr/local/lib/ruby/site_ruby/2.5.0/bundler/spec_set.rb:91:in `block in materialize': Could not find public_suffix-3.0.2 in any of the sources (Bundler::GemNotFound)
	from /usr/local/lib/ruby/site_ruby/2.5.0/bundler/spec_set.rb:85:in `map!'
	from /usr/local/lib/ruby/site_ruby/2.5.0/bundler/spec_set.rb:85:in `materialize'
	from /usr/local/lib/ruby/site_ruby/2.5.0/bundler/definition.rb:171:in `specs'
	...

It is saying that it cannot find some gem. That gem happens to be a testing gem. But I am starting the puma process with my environment set to staging. All the required environment variables are set correctly. The output of env in the container is shown below:

RUBYGEMS_VERSION=2.7.7
BUNDLER_VERSION=1.16.3
PUMA_THREADS_MAX=8
EXECJS_RUNTIME=Disabled
HOSTNAME=8d968df601db
RUBY_VERSION=2.5.1
GEM_HOME=/usr/local/bundle
PUMA_THREADS_MIN=2
RAILS_ROOT=/myapp
PWD=/myapp
HOME=/home/deploy
RAILS_SERVE_STATIC_FILES=true
BUNDLE_PATH=/usr/local/bundle
BUNDLE_APP_CONFIG=/usr/local/bundle
RAILS_ENV=staging
RAILS_LOG_TO_STDOUT=true
TERM=xterm
BUNDLE_SILENCE_ROOT_WARNING=1
RUBY_MAJOR=2.5
SHLVL=1
PUMA_NUM_WORKERS=2
PATH=/usr/local/bundle/bin:/usr/local/bundle/gems/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
_=/usr/bin/env

So, I do not understand why bundler setup is trying to load the development and testing gems.

If I run the puma process without the "bundle exec", like so: puma -C config/puma.rb, then the app works! Comparing the differences between having and not having the "bundle exec", I noticed that the problem was the RUBYOPT="-rbundler/setup" environment variable, which gets set by bundle exec.

For some reason, the bundler setup process is trying to load my development and testing gems.

After more debugging, I have narrowed down the problem to this: there is a BUNDLE_APP_CONFIG environment variable set to /usr/local/bundle/ by the base Ruby docker image. All my gems are also installed to this folder. The bundler config is also in this folder (this config file has the all-important --without / BUNDLE_WITHOUT: "development:test" setting). Bundler is supposed to read this BUNDLE_APP_CONFIG environment variable to find the config file. But this environment variable is not available when bundler/setup is running! So, bundler ends up using a default config, which loads gems from all groups (default, development and test).

To investigate this, I added the following line in /usr/local/lib/ruby/site_ruby/2.5.0/bundler/setup.rb:

puts "++++++++++ In setup.rb = All ENV variables: #{ENV.to_h}."

The output is below (in puma_access.rb):

{"RUBYGEMS_VERSION"=>"2.7.7",
 "BUNDLER_VERSION"=>"1.16.3",
 "PUMA_THREADS_MAX"=>"8",
 "EXECJS_RUNTIME"=>"Disabled",
 "HOSTNAME"=>"8d968df601db",
 "RUBY_VERSION"=>"2.5.1",
 "GEM_HOME"=>"/usr/local/bundle",
 "PUMA_THREADS_MIN"=>"2",
 "RAILS_ROOT"=>"/myapp",
 "PWD"=>"/myapp",
 "HOME"=>"/home/deploy",
 "RAILS_SERVE_STATIC_FILES"=>"true",
 "RAILS_ENV"=>"staging",
 "RAILS_LOG_TO_STDOUT"=>"true",
 "TERM"=>"xterm",
 "RUBY_MAJOR"=>"2.5",
 "RUBYLIB"=>"",
 "SHLVL"=>"1",
 "PUMA_NUM_WORKERS"=>"2",
 "PATH"=>"/usr/local/bundle/bin:/usr/local/bundle/gems/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
 "_"=>"/usr/local/bin/bundle",
 "PUMA_BUNDLER_PRUNED"=>"1",
 "RACK_ENV"=>"staging",
 "BUNDLER_ORIG_BUNDLE_BIN_PATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "BUNDLER_ORIG_BUNDLE_GEMFILE"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "BUNDLER_ORIG_BUNDLER_ORIG_MANPATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "BUNDLER_ORIG_BUNDLER_VERSION"=>"1.16.3",
 "BUNDLER_ORIG_GEM_HOME"=>"/usr/local/bundle",
 "BUNDLER_ORIG_MANPATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "BUNDLER_ORIG_PATH"=>"/usr/local/bundle/bin:/usr/local/bundle/gems/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
 "BUNDLER_ORIG_RB_USER_INSTALL"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "BUNDLER_ORIG_RUBYOPT"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
 "GEM_PATH"=>""}

You will notice that the BUNDLE_APP_CONFIG environment variable is missing from this list. You will notice that this ENV var IS available in the shell (output of env). It is also available if I run bundle exec env.

Why is this environment variable being removed during the bundler/setup run? I am assuming that this removal is being done by bundler, but I may be wrong. I am not able to find where it is being removed.

Any help would be appreciated. Thank you!

The output of bundle env is attached.
bundle_env.txt

[deivid-rodriguez]

Hei! This looks the same as puma/puma#1593?

I tried to reproduce it, but couldn't... 😞

One question though, does it get fixed if you change

https://github.com/puma/puma/blob/395337df4a3b27cc14eeab048016fb1ee85d2f83/lib/puma/launcher.rb#L267

to use Bundler.with_original_env instead?

[t-anjan]

That's it! Changing that line in the Puma gem's launcher.rb fixed the problem. Now, the list of environment variables is (as printed in bundler/setup):

{ "RUBYGEMS_VERSION"=>"2.7.7",
  "BUNDLER_VERSION"=>"1.16.3",
  "PUMA_THREADS_MAX"=>"8",
  "EXECJS_RUNTIME"=>"Disabled",
  "HOSTNAME"=>"cc4042365546",
  "RUBY_VERSION"=>"2.5.1",
  "GEM_HOME"=>"/usr/local/bundle",
  "PUMA_THREADS_MIN"=>"2",
  "RAILS_ROOT"=>"/myapp",
  "PWD"=>"/myapp",
  "HOME"=>"/home/deploy",
  "RAILS_SERVE_STATIC_FILES"=>"true",
  "BUNDLE_PATH"=>"/usr/local/bundle",
  "BUNDLE_APP_CONFIG"=>"/usr/local/bundle",    <<<< IT IS PRESENT NOW!
  "RAILS_ENV"=>"staging",
  "RAILS_LOG_TO_STDOUT"=>"true",
  "TERM"=>"xterm",
  "BUNDLE_SILENCE_ROOT_WARNING"=>"1",
  "RUBY_MAJOR"=>"2.5",
  "SHLVL"=>"1",
  "PUMA_NUM_WORKERS"=>"2",
  "PATH"=>"/usr/local/bundle/bin:/usr/local/bundle/gems/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
  "_"=>"/usr/local/bin/bundle",
  "PUMA_BUNDLER_PRUNED"=>"1",
  "RACK_ENV"=>"staging",
  "BUNDLER_ORIG_BUNDLE_BIN_PATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_BUNDLE_GEMFILE"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_BUNDLER_ORIG_MANPATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_BUNDLER_VERSION"=>"1.16.3",
  "BUNDLER_ORIG_GEM_HOME"=>"/usr/local/bundle",
  "BUNDLER_ORIG_GEM_PATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_MANPATH"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_PATH"=>"/usr/local/bundle/bin:/usr/local/bundle/gems/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
  "BUNDLER_ORIG_RB_USER_INSTALL"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_RUBYLIB"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL",
  "BUNDLER_ORIG_RUBYOPT"=>"BUNDLER_ENVIRONMENT_PRESERVER_INTENTIONALLY_NIL"}

Thanks you very much @deivid-rodriguez for pointing out that the problem is with Puma. I was looking for all usages of with_clean_env within the Bundler gem. I did not realise that the problem could also be due to a deprecated usage in Puma.

I am surprised that you were not able to reproduce it. I am not doing anything out of the ordinary. My usage is as vanilla as it can be. Please let me know if you need any other information from me.

And let me know if I should close this issue and add on to issue 1593 in Puma?

[deivid-rodriguez]

I'm glad it works for you!

I was also surprised that I couldn't reproduce. If my blind guess didn't work I was going to ask you, where does the "bundler/setup" causing the issue gets added to RUBYOPT?. My guess was https://github.com/puma/puma/blob/395337df4a3b27cc14eeab048016fb1ee85d2f83/lib/puma/launcher.rb#L169-L173, but after bundler is pruned, I couldn't get those lines to be triggered.

Regarding the with_clean_env vs with_original_env switch, there's probably some work, docs and discussion yet to happen in bundler, but they are not specific to this issue. So I think this can be closed (we can continue discussing on the closed issue).

[t-anjan]

I thought the RUBYOPT environment variable was set by bundler itself (when doing bundle exec) and not by some piece of code within puma.

[deivid-rodriguez]

You're right, bundle exec should also set that. But I couldn't reproduce the issue with a simple boot of puma through bundle exec and also your environment (I assumed the dump is right before the crash) shows PUMA_BUNDLER_PRUNED. That means it's happening after puma prunes bundler, so I assumed it was not the initial bundle exec causing the issue.