From 184b87b1ce0f768334c348b8c3365641c7aa322b Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Wed, 8 Dec 2021 11:04:36 -0800 Subject: [PATCH 1/6] Status bar notifications --- .../Logger/NuGetFileLogger.cs | 18 ++++++++++++++++-- .../RestoreOperationLogger.cs | 2 ++ 2 files changed, 18 insertions(+), 2 deletions(-) diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs index 73326a48822..e37f2a4b360 100644 --- 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,10 @@ public void Write(string logMessage) lock (_streamWriterLock) { - _streamWriter.Value.WriteLine(FormatWithTime(logMessage)); + if (ShouldFormatWithTime) + { + _streamWriter.Value.WriteLine(FormatWithTime(logMessage)); + } } } diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs index 4466e3bbeac..1ca9e6dd7cd 100644 --- a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs +++ b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs @@ -604,6 +604,8 @@ public override async Task ReportProgressAsync( _statusBar.SetText(progressMessage); + NuGetFileLogger.DefaultInstance.Write(progressMessage); + if (totalSteps != 0) { _statusBar.Progress(ref _cookie, 1, "", currentStep, totalSteps); From a5bc15fdeb4809404781c4b489761f447653c436 Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Wed, 8 Dec 2021 16:28:56 -0800 Subject: [PATCH 2/6] Cleanup --- .../NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs index e37f2a4b360..65ab9b93001 100644 --- a/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs +++ b/src/NuGet.Clients/NuGet.SolutionRestoreManager/Logger/NuGetFileLogger.cs @@ -95,10 +95,13 @@ public void Write(string logMessage) lock (_streamWriterLock) { + string message = logMessage; if (ShouldFormatWithTime) { - _streamWriter.Value.WriteLine(FormatWithTime(logMessage)); + message = FormatWithTime(logMessage); } + _streamWriter.Value.WriteLine(message); + } } From bbe6365eb74d1d6c8f4f6b2fd86bcf959cbb0d31 Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Thu, 9 Dec 2021 14:09:19 -0800 Subject: [PATCH 3/6] Fix the status bar --- .../RestoreOperationLogger.cs | 69 +------------------ .../RestoreCommand/RestoreRunner.cs | 2 +- 2 files changed, 3 insertions(+), 68 deletions(-) diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs index 1ca9e6dd7cd..206a3f63958 100644 --- a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs +++ b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs @@ -213,12 +213,12 @@ 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 + && GetMSBuildLevel(logMessage.Level) == MSBuildVerbosityLevel.Minimal && logMessage.Message.Length == logMessage.Message.TrimStart().Length; } @@ -468,71 +468,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 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 index 7a4761cc325..f718408b682 100644 --- 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 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) From ba65ff908c02a238e273bb9e7af628513889a1df Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Thu, 9 Dec 2021 14:10:55 -0800 Subject: [PATCH 4/6] Cleanup debug only change --- .../NuGet.SolutionRestoreManager/RestoreOperationLogger.cs | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs index 206a3f63958..5cdc75676ea 100644 --- a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs +++ b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs @@ -539,8 +539,6 @@ public override async Task ReportProgressAsync( _statusBar.SetText(progressMessage); - NuGetFileLogger.DefaultInstance.Write(progressMessage); - if (totalSteps != 0) { _statusBar.Progress(ref _cookie, 1, "", currentStep, totalSteps); From 0d34fabc0831047c9487a7b66c6ee2b0ef2eadc2 Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Thu, 9 Dec 2021 15:19:21 -0800 Subject: [PATCH 5/6] Use a more efficient is string indented check --- .../NuGet.SolutionRestoreManager/RestoreOperationLogger.cs | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs index 5cdc75676ea..6dbf5d3412a 100644 --- a/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs +++ b/src/NuGet.Clients/NuGet.SolutionRestoreManager/RestoreOperationLogger.cs @@ -219,7 +219,12 @@ private static bool ShouldReportProgress(ILogMessage logMessage) // they are missing the context of the parent text above it return RestoreOperationProgressUI.Current != null && GetMSBuildLevel(logMessage.Level) == MSBuildVerbosityLevel.Minimal - && logMessage.Message.Length == logMessage.Message.TrimStart().Length; + && !IsStringIndented(logMessage); + + static bool IsStringIndented(ILogMessage logMessage) + { + return logMessage.Message.Length > 0 && char.IsWhiteSpace(logMessage.Message[0]); + } } /// From 5fc5c3f1cafdbe9642aec180cfef1ba5977c3203 Mon Sep 17 00:00:00 2001 From: Nikolche Kolev Date: Thu, 9 Dec 2021 15:58:54 -0800 Subject: [PATCH 6/6] Remove test for unused class --- .../RestoreOperationLoggerTests.cs | 16 ---------------- 1 file changed, 16 deletions(-) diff --git a/test/NuGet.Clients.Tests/NuGet.SolutionRestoreManager.Test/RestoreOperationLoggerTests.cs b/test/NuGet.Clients.Tests/NuGet.SolutionRestoreManager.Test/RestoreOperationLoggerTests.cs index f2aa7db0f72..3637aedddba 100644 --- 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(async () => await tsk); - } - [Fact] public async Task StatusBarProgress_StartAsync_CancellationTokenThrowsAsync() {