Skip to content

Conversation

@jordan-brough
Copy link

@jordan-brough jordan-brough commented Dec 3, 2025

The recently-added "Installed in" and "Downloaded in" timing outputs are much appreciated 🙏

I'd like to suggest we enable them 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.

We had some discussion of this previously in #7622 and had decided on always displaying the timings.

Or, if we don't want to enable the output by default, would we be ok with adding an --timing option, to allow outputing even when DEBUG=true is not set?

i.e. like:

if Bundler.settings[:timing]
  Bundler.ui.confirm "Installed #{spec.name} in: #{format("%.3f", Time.now - start_time)}s"
end

?

Make sure the following tasks are checked

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
```
?
@colby-swandale
Copy link
Member

I like the idea of a timing configuration option that users can set

@jordan-brough
Copy link
Author

👍 Shall I go ahead and update the PR with that?

@hsbt
Copy link
Member

hsbt commented Dec 4, 2025

I'm not sure what is useful for all users.

I know stats is important to maintain CI or dev environment. But I always ignore execution times unless I'm trying to improve them, and I'm sure many users do too. Because I don't want to show them always.

If you are serious about making some improvements, you can use DEBUG=1 and profile as shown below, but are there any other reasons why you would like to add options?

❯ DEBUG=1 bundle i | grep -E "Installed|Downloaded"
Downloaded stringio in: 0.028s
Downloaded sqlite3 in: 0.184s
Installed sqlite3 in: 2.175s
Installed stringio in: 3.192s

@jordan-brough
Copy link
Author

jordan-brough commented Dec 4, 2025

@hsbt -

DEBUG=1 bundle i | grep -E "Installed|Downloaded"

I'd really like something I can leave on by default in CI/CD, at least.
As a user I don't know what useful output I might filter out with something like that. Now or in the future as Bundler changes. And DEBUG outputs a lot of stuff that's hard to target to filter out via grep.

Looking at the high-level: Personally I typically want either:

  1. --quiet mode, OR
  2. useful progress info

I think showing the start and the finish (with timing) of installation would be a great default for non---quiet mode.

i.e. what if this were the default:

❯ bundle install
Starting stringio 3.1.7 with native extensions
Starting sqlite3 2.8.1 with native extensions
Finished sqlite3 in: 2.175s
Finished stringio in: 3.192s

And if I'd like to have more timing information I would appreciate having this:

❯ bundle install --timing
Starting stringio 3.1.7 with native extensions
Starting sqlite3 2.8.1 with native extensions
Downloaded stringio in: 0.128s
Downloaded sqlite3 in: 0.343s
Installed sqlite3 in: 2.047s
Installed stringio in: 3.064s
Finished sqlite3 in: 2.175s
Finished stringio in: 3.192s

When something is slow and I didn't expect it, it's painful to have to redo things with DEBUG because:

  1. DEBUG is very vebose (and hard to filter long-term, see above comments)
  2. Locally I'd have to uninstall all gems from the Gemfile and then reinstall to figure out which gems were slow
  3. On CI/CD it can be a pain to re-run with different arguments, including possibly having to break Docker caches, etc.

What do you think?

@jordan-brough
Copy link
Author

jordan-brough commented Dec 4, 2025

Here's a real example:

Current default output
❯ bundle config set --local force_ruby_platform true
❯ time bundle install

Fetching gem metadata from https://rubygems.org/
Fetching geocoder 1.8.1
Fetching maxminddb 0.1.22
Installing maxminddb 0.1.22
Installing geocoder 1.8.1
Fetching pg 1.5.3
Fetching sqlite3 2.8.1
Installing pg 1.5.3 with native extensions
Installing sqlite3 2.8.1 with native extensions
Fetching html2text 0.4.0
Installing html2text 0.4.0
Fetching scout_apm 5.3.3
Installing scout_apm 5.3.3 with native extensions
Fetching grpc 1.76.0
Installing grpc 1.76.0 with native extensions
Fetching slack-ruby-client 2.7.0
Installing slack-ruby-client 2.7.0
Fetching googleapis-common-protos 1.7.0
Installing googleapis-common-protos 1.7.0
Fetching gapic-common 0.23.0
Fetching grpc-google-iam-v1 1.11.0
Installing gapic-common 0.23.0
Fetching google-cloud-location 0.8.1
Installing grpc-google-iam-v1 1.11.0
Fetching google-iam-v1 1.1.0
Installing google-cloud-location 0.8.1
Fetching google-cloud-dialogflow-v2 1.4.1
Installing google-iam-v1 1.1.0
Fetching google-cloud-translate-v3 1.2.0
Installing google-cloud-dialogflow-v2 1.4.1
Installing google-cloud-translate-v3 1.2.0

1171.99s user 133.33s system 732% cpu 2:58.30 total

☝️ Impossible to tell why it took 3 minutes. Especially with higher --jobs number, like 4.
Even if there were timestamps on each line, I still wouldn't be able to tell.

Suggested default output
❯ bundle config set --local force_ruby_platform true
❯ bundle install

Fetching gem metadata from https://rubygems.org/
Starting geocoder 1.8.1
Starting maxminddb 0.1.22
Installed maxminddb in: 0.006s
Starting pg 1.5.3 with native extensions
Installed geocoder in: 0.019s
Starting sqlite3 2.8.1 with native extensions
Installed pg in: 3.338s
Starting html2text 0.4.0
Installed html2text in: 0.002s
Starting scout_apm 5.3.3 with native extensions
Installed scout_apm in: 0.568s
Starting grpc 1.76.0 with native extensions
Installed sqlite3 in: 44.185s
Starting slack-ruby-client 2.7.0
Installed slack-ruby-client in: 0.185s
Installed grpc in: 171.983s
Starting googleapis-common-protos 1.7.0
Installed googleapis-common-protos in: 0.005s
Starting gapic-common 0.23.0
Starting grpc-google-iam-v1 1.11.0
Installed gapic-common in: 0.007s
Starting google-cloud-location 0.8.1
Installed grpc-google-iam-v1 in: 0.002s
Starting google-iam-v1 1.1.0
Installed google-cloud-location in: 0.004s
Starting google-cloud-dialogflow-v2 1.4.1
Installed google-iam-v1 in: 0.005s
Starting google-cloud-translate-v3 1.2.0
Installed google-cloud-translate-v3 in: 0.021s
Installed google-cloud-dialogflow-v2 in: 0.065s

☝️ Very easy to find out that sqlite3 and grpc were the culprits. And it's no more verbose than the current bundler output.

@jordan-brough
Copy link
Author

jordan-brough commented Dec 4, 2025

Another idea, if we want to reduce output even more than we currently are:

Limit the default output to just Installed some-gem in: XXXs.
And expose the other lines if --timing is supplied, or maybe just if DEBUG is enabled.

The Installed line w/ timing is the most useful line, imo. Especially when --jobs is > 0, which I'd guess it is for most situations.

Just a thought.

@Edouard-chin
Copy link
Contributor

👋 The reason I added the timing information during debugging was because I felt that printing it by default wouldn't provide any value to regular users.

Very easy to find out that sqlite3 and grpc were the culprits. And it's no more verbose than the current bundler output.

I guess the question that remains is: if you were to know that this is slow, do you think this would incline users to investigate the problem and fix it, or would it just be "oh it's slow because of that" ?

I see this timing information similar ish to the browser console. On a day to day basis I don't really care to know how long a web page takes to load. But if it annoys me I can rely on the console tools and investigate the issue, but I wouldn't want that console to be turned on all the time. I hope my rationale make sense 😅

@jordan-brough
Copy link
Author

if you were to know that this is slow, do you think this would incline users to investigate the problem and fix it, or would it just be "oh it's slow because of that" ?

I think it would definitely encourage them to fix it!
If we output at least the total time (per gem) by default, I think it's much more likely devs will investigate. Doesn't take extra work to get the data out and they know where to start looking.

Having the data possible via DEBUG is a great improvement! I wouldn't want to leave that on all the time in my CI/CD though. Yet I'd like to always have that timing info there so that when I want it it's already there.

@jordan-brough
Copy link
Author

jordan-brough commented Dec 4, 2025

We don't need to make it much more verbose for the user btw.
Even if we just turned off "Installing" by default and turned on "Installed", that would be a huge win, imo, and not really any more verbose.

E.g. change the default from this:

Fetching grpc 1.76.0
Installing grpc 1.76.0 with native extensions

To this:

Fetching grpc 1.76.0
Installed grpc 1.7.60 with native extensions in: 171.983s

Doesn't feel significantly more verbose?

But even if we don't change the default, having something reasonable (i.e. not all of DEBUG) that I can leave turned on (e.g. --timing) would be very helpful imo.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants