Bundler: Show "Installed" message after installing a gem #7622
Conversation
Make it easier to tell how long it took to install a gem. When installing gems in parallel (e.g. `bundle install --jobs 4`), make it easier to tell when a gem has finished installing and how long each gem took to install. Currently, when reviewing logs on production servers, I have timestamps on log lines but I still can't tell which gems are taking a long time to install because I can't get a time diff between starting a particular gem and finishing the install (if I'm installing gems in parallel). Example output: ``` Fetching buffering_logger 3.1.1 Installing buffering_logger 3.1.1 Installed buffering_logger 3.1.1 in 0.004s ```
|
Thanks for opening a pull request and helping make RubyGems and Bundler better! Someone from the RubyGems team will take a look at your pull request shortly and leave any feedback. Please make sure that your pull request has tests for any changes or added functionality. We use GitHub Actions to test and make sure your change works functionally and uses acceptable conventions, you can review the current progress of GitHub Actions in the PR status window below. If you have any questions or concerns that you wish to ask, feel free to leave a comment in this PR or join our #rubygems or #bundler channel on Slack. For more information about contributing to the RubyGems project feel free to review our CONTRIBUTING guide |
|
This is great, and fixes an issue other people have experienced! See #3305. One thought I'm having is that in #3305 (comment), people also complained about output being complicated to parse with two separate (possibly not consecutive) lines per gem. So even if this change will help clarify which gem took longer to install, it will make the output even more complicated with 3 lines per gem. I wonder if we could fix this problem (unclarity of which gems took long to install) while keeping the out as verbose as it is now, by instead of adding the "Installed " line to the output, make it replace the "Installing" line? |
Personally I don't mind extra output, and the difference between fetching & installing could be important in some cases (network issues?). But that's an much less important edge case. I'm happy as long as I get a "start" and "stop" marker! I'll update to remove the "Installing" line and I'll add some tests. |
And move "with native extensions" to "Installing".
You're right, and I'm not totally sold on my own suggestion. It was mostly brainstorming to try add the useful information being added here without increasing the number of lines logged. Maybe, iterating on the suggestion, we could change everything to "after the fact" info, like |
|
Hm, if we want to limit to 2 lines, personally I'd prefer to have "start" and "finished" lines, so if e.g. fetching is hung at any point I can still understand what the system is trying to do right now (I can see that it started but never finished). From a "debug stuff" perspective I'd prefer to have all of these:
But if we want to be concise then the first and last seem the best to pick imo. |
|
All good points! Keeping only "Fetching" and "Installed" may have issues too, since "Fetching" does not show up if the gem is already cached. I'm not fully convinced but I guess all 4 would be best, indeed. If users are bothered enough about multiple lines in output per gem, they could open a new issue. Ideally we would fix this "the right way" by properly parallelizing the input so that it just shows one line per gem that's updated with final execution time and status once done. But that's much more tricky to implement. I wonder what @simi thinks since he participated in the linked issue too. |
|
@deivid-rodriguez should I go ahead and implement displaying all 4 messages, or do we want to wait to hear back from @simi or others? |
|
Since I wouldn't want you to waste effort going in a direction we may end up changing, I'd say let's wait a bit for more input. |
|
@deivid-rodriguez how long would you like to wait to see if someone else wants to chime in? |
|
I think we can go with the suggested approach 👍. After all, @simi was ok with this in the linked issue and the main thing to figure out is when to release the change, not the change itself. In the future, I'd like to use something like https://github.com/piotrmurach/tty-progressbar#ttyprogressbar to get the best of both worlds (useful and condensed output), but that's a non trivial project. |
|
Sorry for chiming in late. Change looks good. Finding the balance is hard here to not overhelm users with a lot of info. It is wise to show something as early as possible (thus the starting message of Fetching...) and info about the end (Installed...). The only problem I do see is in the different verb used - Fetching abc -> Installed abc. Is that acceptable? @jordan-brough would you mind to rebase? |
|
Fetching/Installed sounds good to me 👍 |
3 participants
Add an "Installed XXX in Y.YYYs" message after installing a gem.
Example output:
☝️ the last line is new.
What was the end-user or developer problem that led to this PR?
When installing gems in parallel (e.g.
bundle install --jobs 4), I wanted it to be easier to tell when each gem finished installing and how long each gem took to install.Currently, especially when reviewing logs on production servers, I have timestamps on log lines but I still can't tell which gems are taking a long time to install because I can't get a time diff between starting a particular gem and finishing the install (if I'm installing gems in parallel). Gems with native extensions are often ones that are slow that I'd like to identify.
What is your fix for the problem, implemented in this PR?
Measure the time elapsed while installing (not including fetching) and print it out.
If this looks OK I will add some tests.
Make sure the following tasks are checked