Reduce status bar spam, log only minimal message to the status bar #4366
Conversation
|
I'd appreciate a review here. |
| @@ -24,6 +24,8 @@ internal sealed class NuGetFileLogger : IDisposable | |||
|
|
|||
| public bool IsEnabled { get; } | |||
|
|
|||
| public bool ShouldFormatWithTime { get; } | |||
There was a problem hiding this comment.
Note that this logger is a testing utility that's only built under debug, so changes here don't affect the product.
| @@ -468,71 +468,6 @@ private static LogLevel GetLogLevel(MSBuildVerbosityLevel level) | |||
| } | |||
| } | |||
|
|
|||
| internal class WaitDialogProgress : RestoreOperationProgressUI | |||
There was a problem hiding this comment.
Unused class, just kept creating extra refs to some methods.
| @@ -259,7 +259,7 @@ public static async Task<RestoreSummary> CommitAsync(RestoreResultPair restoreRe | |||
| var log = summaryRequest.Request.Log; | |||
|
|
|||
| // Commit the result | |||
| log.LogInformation(Strings.Log_Committing); | |||
| log.LogVerbose(Strings.Log_Committing); | |||
There was a problem hiding this comment.
I seriously considered removing this.
It literally just says "Comitting restore" which is not extremely helpful but it is a progress indicator.
For now, I just moved it verbose, but we can totally change it if others strongly lean one way or another.
| // Do not show errors, warnings, verbose or debug messages on the progress dialog | ||
| // Avoid showing indented messages, these are typically not useful for the progress dialog since | ||
| // they are missing the context of the parent text above it | ||
| return RestoreOperationProgressUI.Current != null | ||
| && GetMSBuildLevel(logMessage.Level) == MSBuildVerbosityLevel.Normal | ||
| && GetMSBuildLevel(logMessage.Level) == MSBuildVerbosityLevel.Minimal |
There was a problem hiding this comment.
This is the "big" change.
src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs
Outdated
Show resolved
Hide resolved
|
I like the cleaner output |
|
|
||
| static bool IsStringIndented(ILogMessage logMessage) | ||
| { | ||
| return logMessage.Message.Length > 0 && char.IsWhiteSpace(logMessage.Message[0]); |
|
Here's all my feedback in a huge comment. In my opinion, if these are already downloaded, there's little need to even show these or say "Already Downloaded"? If they aren't downloaded, then saying "Downloading <...>". (Also do we care about index.json here? Ultimately we just care about downloading the package based on the index). So my thoughts would be: For the following: Wonderful! I know these were downloaded & successfully installed. Is the path where it's installed useful here? (i.e. Installed NuGet.Common 6.0.0 (PATH) from ...) If the line above says Also this comment is interesting:
From just looking at the output, this always has confused me. Why is restore doing multiple restores & logging such? This output does not make sense to me. I would expect a similar structure to the examples I have above about scope. Lastly there's mention about Bonus thought: Can we indent sections as they pertain to the current task they are doing for readability? For example: My two cents! This is a great PR as it stands & simplifies many things. Great job Nikolche! |
|
Thanks for the long comment @JonDouglas! Super helpful! I've created some follow ups based on your feedback, some of which I might try to get done in customer sprint if I have time.
The way it was designed originally, it's all http details that are included.
Good point. I've created NuGet/Home#11447.
Restore in Visual Studio is always a solution restore.
It's kind of funny how you diagnosed the problem from the output :D
We're using that message as a progress indicator, telling you restore started in VS. Today here's what we do: MInimal verbosity - Indication of start Note that there may be many project messages in between.
Unfortunately that one is pretty hard. A package installation may happen for multiple projects at once, and that is not tracked today. |
Bug
Fixes: NuGet/Home#4376
Fixes: NuGet/Home#6047
Regression? Last working version:
Description
NuGet has generally relevant logs at normal verbosity, but the logs on the status bar are not super thought through.
This PR changes that.
Note These are not are the final changes in this area. There are other components/APIs we can use for reporting progress, but that's a different change tracked in NuGet/Home#9396.
All the logs and tests below were performed on a solution with 1 PackageReference and 1 packages.config project each.
Here's the before on what gets logged to the Output Window on Normal Verbosity.
Here's the after.
Here's my reasoning for why the after output is as is.
CACHEmessages were there to indicate the remote calls NuGet makes/attempts to make. They are useful for auditing.Here's the before and after for the Status Bar when a clean restore happens.
Before:
After:
Note that the above version has a lot of fluff.
Details about starting/ending restore and the individual packages installed + some fluff messages such as
Committing restoreare absolutely irrelevant for the status bar.The new version does contain 2
Restoring NuGet packages...lines, but that's a larger refactoring that if people feel is super relevant I can create an issue for.Finally here are the changes for the first no-op restores.
Output Window - Before:
Output Window - After;
Note that details about the assets file not changing has been deemed relevant in the past. We can rethink that/change it, but I'm solving one problem at a time :)
Status bar - Before
Status bar - After
Now the last part is a bit controversial.
No actual restore happened, and there's no indication of that in the status bar. The trikc is that once you're done with a status bar, it switches to
Readywhich is indicative of operation completion. So I propose not to complicate things by adding an extra message there.Finally:
Note that every 2nd no-op logs nothing to the Status bar, and that's true before and after my change.
PR Checklist
PR has a meaningful title
PR has a linked issue.
Described changes
Tests
Documentation