Reduce status bar spam, log only minimal message to the status bar (#…

…4366)
NuGet · Dec 10, 2021 · da818d7 · da818d7
1 parent 9a830a0
commit da818d7
Show file tree

Hide file tree

Showing 4 changed files with 28 additions and 87 deletions.
diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs
@@ -24,6 +24,8 @@ internal sealed class NuGetFileLogger : IDisposable
 
         public bool IsEnabled { get; }
 
+        public bool ShouldFormatWithTime { get; }
+
         // The DateTimeOffset and Stopwatch ticks are not equivalent. 1/10000000 is 1 DateTime tick.
         public DateTimeOffset Now => _startTime.AddTicks(_stopwatch.ElapsedTicks * 10000000 / Stopwatch.Frequency);
 
@@ -34,13 +36,22 @@ internal NuGetFileLogger(IEnvironmentVariableReader environmentVariableReader)
                 throw new ArgumentNullException(nameof(environmentVariableReader));
             }
 
-            _logDirectoryPath = environmentVariableReader.GetEnvironmentVariable("NUGET_SOLUTION_LOAD_LOGGING_PATH");
+            _logDirectoryPath = environmentVariableReader.GetEnvironmentVariable("NUGET_VS_RESTORE_LOGGING_PATH");
 
             if (!string.IsNullOrWhiteSpace(_logDirectoryPath))
             {
                 IsEnabled = true;
             }
 
+            var formatWithTime = environmentVariableReader.GetEnvironmentVariable("NUGET_VS_RESTORE_FORMAT_WITH_TIME");
+
+            if (!string.IsNullOrWhiteSpace(formatWithTime))
+            {
+                _ = bool.TryParse(formatWithTime, out bool formatWithTimeOverride);
+
+                ShouldFormatWithTime = formatWithTimeOverride;
+            }
+
             _startTime = DateTimeOffset.UtcNow;
             _stopwatch = Stopwatch.StartNew();
 
@@ -84,7 +95,13 @@ public void Write(string logMessage)
 
             lock (_streamWriterLock)
             {
-                _streamWriter.Value.WriteLine(FormatWithTime(logMessage));
+                string message = logMessage;
+                if (ShouldFormatWithTime)
+                {
+                    message = FormatWithTime(logMessage);
+                }
+                _streamWriter.Value.WriteLine(message);
+
             }
         }
 

diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs
@@ -213,13 +213,18 @@ private void HandleErrorsAndWarnings(ILogMessage logMessage)
 
         private static bool ShouldReportProgress(ILogMessage logMessage)
         {
-            // Only show messages with VerbosityLevel.Normal. That is, info messages only.
+            // Only show messages with VerbosityLevel.Minimal.
             // 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
-                && logMessage.Message.Length == logMessage.Message.TrimStart().Length;
+                && GetMSBuildLevel(logMessage.Level) == MSBuildVerbosityLevel.Minimal
+                && !IsStringIndented(logMessage);
+
+            static bool IsStringIndented(ILogMessage logMessage)
+            {
+                return logMessage.Message.Length > 0 && char.IsWhiteSpace(logMessage.Message[0]);
+            }
         }
 
         /// <summary>
@@ -468,71 +473,6 @@ private static LogLevel GetLogLevel(MSBuildVerbosityLevel level)
             }
         }
 
-        internal class WaitDialogProgress : RestoreOperationProgressUI
-        {
-            private readonly ThreadedWaitDialogHelper.Session _session;
-            private readonly JoinableTaskFactory _taskFactory;
-
-            private WaitDialogProgress(
-                ThreadedWaitDialogHelper.Session session,
-                JoinableTaskFactory taskFactory)
-            {
-                _session = session;
-                _taskFactory = taskFactory;
-                UserCancellationToken = _session.UserCancellationToken;
-            }
-
-            public static async Task<RestoreOperationProgressUI> StartAsync(
-                IAsyncServiceProvider asyncServiceProvider,
-                JoinableTaskFactory jtf,
-                CancellationToken token)
-            {
-                token.ThrowIfCancellationRequested();
-
-                await jtf.SwitchToMainThreadAsync(token);
-
-                var waitDialogFactory = await asyncServiceProvider.GetServiceAsync<
-                    SVsThreadedWaitDialogFactory, IVsThreadedWaitDialogFactory>();
-
-                var session = waitDialogFactory.StartWaitDialog(
-                    waitCaption: Resources.DialogTitle,
-                    initialProgress: new ThreadedWaitDialogProgressData(
-                        Resources.RestoringPackages,
-                        progressText: string.Empty,
-                        statusBarText: string.Empty,
-                        isCancelable: true,
-                        currentStep: 0,
-                        totalSteps: 0));
-
-                return new WaitDialogProgress(session, jtf);
-            }
-
-            public async override ValueTask DisposeAsync()
-            {
-                await _taskFactory.SwitchToMainThreadAsync();
-                _session.Dispose();
-            }
-
-            public override async Task ReportProgressAsync(
-                string progressMessage,
-                uint currentStep,
-                uint totalSteps)
-            {
-                await _taskFactory.SwitchToMainThreadAsync();
-
-                // When both currentStep and totalSteps are 0, we get a marquee on the dialog
-                var progressData = new ThreadedWaitDialogProgressData(
-                    progressMessage,
-                    progressText: string.Empty,
-                    statusBarText: string.Empty,
-                    isCancelable: true,
-                    currentStep: (int)currentStep,
-                    totalSteps: (int)totalSteps);
-
-                _session.Progress.Report(progressData);
-            }
-        }
-
         internal class StatusBarProgress : RestoreOperationProgressUI
         {
             private static object Icon = (short)Constants.SBAI_General;

diff --git a/src/NuGet.Core/NuGet.Commands/RestoreCommand/RestoreRunner.cs b/src/NuGet.Core/NuGet.Commands/RestoreCommand/RestoreRunner.cs
@@ -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);
             await result.CommitAsync(log, token);
 
             if (result.Success)

diff --git a/test/NuGet.Clients.Tests/NuGet.SolutionRestoreManager.Test/RestoreOperationLoggerTests.cs b/test/NuGet.Clients.Tests/NuGet.SolutionRestoreManager.Test/RestoreOperationLoggerTests.cs
@@ -12,22 +12,6 @@ namespace NuGet.SolutionRestoreManager.Test
     [Collection(MockedVS.Collection)]
     public class RestoreOperationLoggerTests
     {
-        [Fact]
-        public async Task WaitDialogProgress_StartAsync_CancellationTokenThrowsAsync()
-        {
-            // Prepare
-            var cts = new CancellationTokenSource();
-
-            var tsk = RestoreOperationLogger.WaitDialogProgress.StartAsync(
-                AsyncServiceProvider.GlobalProvider,
-                ThreadHelper.JoinableTaskFactory,
-                cts.Token);
-            cts.Cancel();
-
-            // Act and Assert
-            await Assert.ThrowsAsync<OperationCanceledException>(async () => await tsk);
-        }
-
         [Fact]
         public async Task StatusBarProgress_StartAsync_CancellationTokenThrowsAsync()
         {