From ef8670abdd9626095e00424ff9abacef8fb63128 Mon Sep 17 00:00:00 2001 From: Jordan Brough Date: Wed, 3 Dec 2025 08:36:44 -0700 Subject: [PATCH] Always show install times during bundle install I'd like to suggest that we display the recently-added "Installed in" and "Downloaded in" outputs by default, rather than only when DEBUG=true. It's very common to: - Run bundle install during deploys or CI - Have `--jobs` > 1 - Have some gems take a very long time to install. E.g. ones with native extensions. When `--jobs` > 1, it's impossible to tell which gems are slow, unless "Installed In" is displayed. DEBUG=true is **very** verbose, and seems like too much for this common need. This feels like a common enough case to output the new timings by default. Or, if we don't want to enable it by default, would we be ok with adding an `--timing` option, to allow outputing even when `DEBUG=true` is not set? i.e. like: ```ruby if Bundler.settings[:timing] Bundler.ui.confirm "Installed #{spec.name} in: #{format("%.3f", Time.now - start_time)}s" end ``` ? --- bundler/lib/bundler/source/rubygems.rb | 14 ++++++-------- bundler/spec/bundler/source/rubygems_spec.rb | 4 ++-- bundler/spec/commands/update_spec.rb | 2 +- bundler/spec/runtime/inline_spec.rb | 2 +- 4 files changed, 10 insertions(+), 12 deletions(-) diff --git a/bundler/lib/bundler/source/rubygems.rb b/bundler/lib/bundler/source/rubygems.rb index e1e030ffc899..f9086958f3d0 100644 --- a/bundler/lib/bundler/source/rubygems.rb +++ b/bundler/lib/bundler/source/rubygems.rb @@ -211,11 +211,9 @@ def install(spec, options = {}) message += " with native extensions" if spec.extensions.any? Bundler.ui.confirm message - installed_spec = nil - - Gem.time("Installed #{spec.name} in", 0, true) do - installed_spec = installer.install - end + start_time = Time.now + installed_spec = installer.install + Bundler.ui.confirm "Installed #{spec.name} in: #{format("%.3f", Time.now - start_time)}s" spec.full_gem_path = installed_spec.full_gem_path spec.loaded_from = installed_spec.loaded_from @@ -483,9 +481,9 @@ def download_gem(spec, download_cache_path, previous_spec = nil) Bundler.ui.confirm("Fetching #{version_message(spec, previous_spec)}") gem_remote_fetcher = remote_fetchers.fetch(spec.remote).gem_remote_fetcher - Gem.time("Downloaded #{spec.name} in", 0, true) do - Bundler.rubygems.download_gem(spec, uri, download_cache_path, gem_remote_fetcher) - end + start_time = Time.now + Bundler.rubygems.download_gem(spec, uri, download_cache_path, gem_remote_fetcher) + Bundler.ui.confirm "Downloaded #{spec.name} in: #{format("%.3f", Time.now - start_time)}s" end # Returns the global cache path of the calling Rubygems::Source object. diff --git a/bundler/spec/bundler/source/rubygems_spec.rb b/bundler/spec/bundler/source/rubygems_spec.rb index dde4e4ed4769..7981006b5db8 100644 --- a/bundler/spec/bundler/source/rubygems_spec.rb +++ b/bundler/spec/bundler/source/rubygems_spec.rb @@ -45,7 +45,7 @@ end end - describe "log debug information" do + describe "log timing information" do it "log the time spent downloading and installing a gem" do build_repo2 do build_gem "warning" @@ -56,7 +56,7 @@ gem "warning" G - stdout = install_gemfile(gemfile_content, env: { "DEBUG" => "1" }) + stdout = install_gemfile(gemfile_content) expect(stdout).to match(/Downloaded warning in: \d+\.\d+s/) expect(stdout).to match(/Installed warning in: \d+\.\d+s/) diff --git a/bundler/spec/commands/update_spec.rb b/bundler/spec/commands/update_spec.rb index cdaeb75c4a33..552df5acf334 100644 --- a/bundler/spec/commands/update_spec.rb +++ b/bundler/spec/commands/update_spec.rb @@ -981,7 +981,7 @@ end bundle "update", all: true - expect(out.sub("Removing foo (1.0)\n", "")).to match(/Resolving dependencies\.\.\.\.*\nFetching foo 2\.0 \(was 1\.0\)\nInstalling foo 2\.0 \(was 1\.0\)\nBundle updated/) + expect(out.sub("Removing foo (1.0)\n", "")).to match(/Resolving dependencies\.\.\.\.*\nFetching foo 2\.0 \(was 1\.0\)\nDownloaded foo in:.*\nInstalling foo 2\.0 \(was 1\.0\)\nInstalled foo in:.*\nBundle updated/) end it "shows error message when Gemfile.lock is not preset and gem is specified" do diff --git a/bundler/spec/runtime/inline_spec.rb b/bundler/spec/runtime/inline_spec.rb index e55d029a4b68..daf7981e1426 100644 --- a/bundler/spec/runtime/inline_spec.rb +++ b/bundler/spec/runtime/inline_spec.rb @@ -108,7 +108,7 @@ def confirm(msg, newline = nil) end RUBY - expect(out).to eq("CONFIRMED!\nCONFIRMED!") + expect(out).to eq("CONFIRMED!\nCONFIRMED!\nCONFIRMED!\nCONFIRMED!") end it "has an option for quiet installation" do