From 6f6be00b5f03424c6baf457156a23e5464bfc1a8 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 10:36:20 +1000 Subject: [PATCH 01/13] Remove unused code Just cleaning things up before I go looking for log messages --- .../Common/BackgroundDocumentGenerator.cs | 373 ------------------ .../DefaultRazorProjectService.cs | 24 -- .../ProjectSystem/RazorProjectService.cs | 2 - .../DefaultProjectSnapshotManager.cs | 153 ------- .../ProjectSnapshotManagerBase.cs | 9 - .../Common/BackgroundDocumentGeneratorTest.cs | 148 ------- .../DefaultRazorProjectServiceTest.cs | 44 --- .../DefaultProjectSnapshotManagerTest.cs | 189 --------- 8 files changed, 942 deletions(-) delete mode 100644 src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/Common/BackgroundDocumentGenerator.cs delete mode 100644 src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/Common/BackgroundDocumentGeneratorTest.cs diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/Common/BackgroundDocumentGenerator.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/Common/BackgroundDocumentGenerator.cs deleted file mode 100644 index 8349a5b9232..00000000000 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/Common/BackgroundDocumentGenerator.cs +++ /dev/null @@ -1,373 +0,0 @@ -// Copyright (c) .NET Foundation. All rights reserved. -// Licensed under the MIT license. See License.txt in the project root for license information. - -using System; -using System.Collections.Generic; -using System.Diagnostics.CodeAnalysis; -using System.Linq; -using System.Threading; -using System.Threading.Tasks; -using Microsoft.AspNetCore.Razor.Language; -using Microsoft.CodeAnalysis.Razor; -using Microsoft.CodeAnalysis.Razor.ProjectSystem; -using Microsoft.VisualStudio.Threading; - -namespace Microsoft.AspNetCore.Razor.LanguageServer.Common; - -internal class BackgroundDocumentGenerator : IProjectSnapshotChangeTrigger -{ - private record struct WorkResult(RazorCodeDocument Output, IDocumentSnapshot Document); - - private readonly ProjectSnapshotManagerDispatcher _dispatcher; - private readonly IEnumerable _listeners; - private readonly Dictionary _work; - private ProjectSnapshotManagerBase? _projectManager; - private Timer? _timer; - private bool _solutionIsClosing; - - public BackgroundDocumentGenerator( - ProjectSnapshotManagerDispatcher dispatcher, - IEnumerable listeners) - { - _dispatcher = dispatcher ?? throw new ArgumentNullException(nameof(dispatcher)); - _listeners = listeners ?? throw new ArgumentNullException(nameof(listeners)); - _work = new Dictionary(); - } - - // For testing only - protected BackgroundDocumentGenerator( - ProjectSnapshotManagerDispatcher dispatcher) - { - _dispatcher = dispatcher; - _work = new Dictionary(); - _listeners = Enumerable.Empty(); - } - - public bool HasPendingNotifications - { - get - { - lock (_work) - { - return _work.Count > 0; - } - } - } - - public TimeSpan Delay { get; set; } = TimeSpan.Zero; - - public bool IsScheduledOrRunning => _timer != null; - - // Used in tests to ensure we can control when background work starts. - public ManualResetEventSlim? BlockBackgroundWorkStart { get; set; } - - // Used in tests to ensure we can know when background work finishes. - public ManualResetEventSlim? NotifyBackgroundWorkStarting { get; set; } - - // Used in unit tests to ensure we can know when background has captured its current workload. - public ManualResetEventSlim? NotifyBackgroundCapturedWorkload { get; set; } - - // Used in tests to ensure we can control when background work completes. - public ManualResetEventSlim? BlockBackgroundWorkCompleting { get; set; } - - // Used in tests to ensure we can know when background work finishes. - public ManualResetEventSlim? NotifyBackgroundWorkCompleted { get; set; } - - [MemberNotNull(nameof(_projectManager))] - public void Initialize(ProjectSnapshotManagerBase projectManager) - { - _projectManager = projectManager; - - _projectManager.Changed += ProjectSnapshotManager_Changed; - - foreach (var documentProcessedListener in _listeners) - { - documentProcessedListener.Initialize(_projectManager); - } - } - - private void OnStartingBackgroundWork() - { - if (BlockBackgroundWorkStart != null) - { - BlockBackgroundWorkStart.Wait(); - BlockBackgroundWorkStart.Reset(); - } - - if (NotifyBackgroundWorkStarting != null) - { - NotifyBackgroundWorkStarting.Set(); - } - } - - private void OnCompletingBackgroundWork() - { - if (BlockBackgroundWorkCompleting != null) - { - BlockBackgroundWorkCompleting.Wait(); - BlockBackgroundWorkCompleting.Reset(); - } - } - - private void OnCompletedBackgroundWork() - { - if (NotifyBackgroundWorkCompleted != null) - { - NotifyBackgroundWorkCompleted.Set(); - } - } - - private void OnBackgroundCapturedWorkload() - { - if (NotifyBackgroundCapturedWorkload != null) - { - NotifyBackgroundCapturedWorkload.Set(); - } - } - - // Internal for testing - internal void Enqueue(IDocumentSnapshot document) - { - _dispatcher.AssertDispatcherThread(); - - lock (_work) - { - // We only want to store the last 'seen' version of any given document. That way when we pick one to process - // it's always the best version to use. - var key = new DocumentKey(document.Project.Key, document.FilePath.AssumeNotNull()); - _work[key] = document; - - StartWorker(); - } - } - - private void StartWorker() - { - // Access to the timer is protected by the lock in Synchronize and in Timer_Tick - // Timer will fire after a fixed delay, but only once. - _timer ??= new Timer(Timer_Tick, null, Delay, Timeout.InfiniteTimeSpan); - } - - private void Timer_Tick(object? state) - { - Timer_TickAsync(CancellationToken.None).Forget(); - } - - private async Task Timer_TickAsync(CancellationToken cancellationToken) - { - try - { - OnStartingBackgroundWork(); - - KeyValuePair[] work; - List results = new(); - lock (_work) - { - work = _work.ToArray(); - _work.Clear(); - } - - OnBackgroundCapturedWorkload(); - - for (var i = 0; i < work.Length; i++) - { - if (_solutionIsClosing) - { - break; - } - - var document = work[i].Value; - try - { - var codeDocument = await document.GetGeneratedOutputAsync().ConfigureAwait(false); - results.Add(new WorkResult(codeDocument, document)); - } - catch (Exception ex) - { - ReportError(ex); - } - } - - OnCompletingBackgroundWork(); - - if (!_solutionIsClosing) - { - await _dispatcher.RunOnDispatcherThreadAsync( - () => NotifyDocumentsProcessed(results), - cancellationToken).ConfigureAwait(false); - } - - lock (_work) - { - // Suppress analyzer that suggests using DisposeAsync(). -#pragma warning disable VSTHRD103 // Call async methods when in an async method - - // Resetting the timer allows another batch of work to start. - _timer?.Dispose(); - _timer = null; - -#pragma warning restore VSTHRD103 - - // If more work came in while we were running start the worker again. - if (_work.Count > 0 && !_solutionIsClosing) - { - StartWorker(); - } - } - - OnCompletedBackgroundWork(); - } - catch (Exception ex) - { - // This is something totally unexpected, let's just send it over to the workspace. - ReportError(ex); - - // Suppress analyzer that suggests using DisposeAsync(). -#pragma warning disable VSTHRD103 // Call async methods when in an async method - - _timer?.Dispose(); - _timer = null; - -#pragma warning restore VSTHRD103 - } - } - - private void NotifyDocumentsProcessed(List results) - { - for (var i = 0; i < results.Count; i++) - { - foreach (var documentProcessedTrigger in _listeners) - { - var document = results[i].Document; - var codeDocument = results[i].Output; - - documentProcessedTrigger.DocumentProcessed(codeDocument, document); - } - } - } - - private void ProjectSnapshotManager_Changed(object? sender, ProjectChangeEventArgs args) - { - // Don't do any work if the solution is closing - if (args.SolutionIsClosing) - { - _solutionIsClosing = true; - return; - } - - _solutionIsClosing = false; - - _dispatcher.AssertDispatcherThread(); - - switch (args.Kind) - { - case ProjectChangeKind.ProjectAdded: - { - var newProject = args.Newer.AssumeNotNull(); - - foreach (var documentFilePath in newProject.DocumentFilePaths) - { - if (newProject.GetDocument(documentFilePath) is { } document) - { - Enqueue(document); - } - } - - break; - } - case ProjectChangeKind.ProjectChanged: - { - var newProject = args.Newer.AssumeNotNull(); - - foreach (var documentFilePath in newProject.DocumentFilePaths) - { - if (newProject.GetDocument(documentFilePath) is { } document) - { - Enqueue(document); - } - } - - break; - } - - case ProjectChangeKind.DocumentAdded: - { - var newProject = args.Newer.AssumeNotNull(); - var documentFilePath = args.DocumentFilePath.AssumeNotNull(); - - if (newProject.GetDocument(documentFilePath) is { } document) - { - Enqueue(document); - - foreach (var relatedDocument in newProject.GetRelatedDocuments(document)) - { - Enqueue(relatedDocument); - } - } - - break; - } - - case ProjectChangeKind.DocumentChanged: - { - var newProject = args.Newer.AssumeNotNull(); - var documentFilePath = args.DocumentFilePath.AssumeNotNull(); - - if (newProject.GetDocument(documentFilePath) is { } document) - { - Enqueue(document); - - foreach (var relatedDocument in newProject.GetRelatedDocuments(document)) - { - Enqueue(relatedDocument); - } - } - - break; - } - - case ProjectChangeKind.DocumentRemoved: - { - var newProject = args.Newer.AssumeNotNull(); - var oldProject = args.Older.AssumeNotNull(); - var documentFilePath = args.DocumentFilePath.AssumeNotNull(); - - if (oldProject.GetDocument(documentFilePath) is { } document) - { - foreach (var relatedDocument in oldProject.GetRelatedDocuments(document)) - { - var relatedDocumentFilePath = relatedDocument.FilePath.AssumeNotNull(); - if (newProject.GetDocument(relatedDocumentFilePath) is { } newRelatedDocument) - { - Enqueue(newRelatedDocument); - } - } - } - - break; - } - case ProjectChangeKind.ProjectRemoved: - { - // ignore - break; - } - - default: - throw new InvalidOperationException(SR.FormatUnknown_ProjectChangeKind(args.Kind)); - } - } - - private void ReportError(Exception ex) - { - if (_projectManager is null) - { - return; - } - - _dispatcher - .RunOnDispatcherThreadAsync( - () => _projectManager.ReportError(ex), - CancellationToken.None) - .Forget(); - } -} diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs index b4f2af7a22f..703abb8eb83 100644 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs +++ b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs @@ -260,30 +260,6 @@ public override ProjectKey AddProject(string filePath, string intermediateOutput return hostProject.Key; } - public override void RemoveProject(string filePath) - { - _projectSnapshotManagerDispatcher.AssertDispatcherThread(); - - var normalizedPath = FilePathNormalizer.Normalize(filePath); - - var projectKeys = _projectSnapshotManagerAccessor.Instance.GetAllProjectKeys(normalizedPath); - foreach (var projectKey in projectKeys) - { - var project = (ProjectSnapshot)_projectSnapshotManagerAccessor.Instance.GetLoadedProject(projectKey); - - if (project is null) - { - // Never tracked the project to begin with, noop. - continue; - } - - _logger.LogInformation("Removing project '{filePath}' from project system.", filePath); - _projectSnapshotManagerAccessor.Instance.ProjectRemoved(project.Key); - - TryMigrateDocumentsFromRemovedProject(project); - } - } - public override void UpdateProject( ProjectKey projectKey, RazorConfiguration? configuration, diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/RazorProjectService.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/RazorProjectService.cs index e1b4abc2558..eced2117d7f 100644 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/RazorProjectService.cs +++ b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/RazorProjectService.cs @@ -24,8 +24,6 @@ internal abstract class RazorProjectService public abstract ProjectKey AddProject(string filePath, string intermediateOutputPath, RazorConfiguration? configuration, string? rootNamespace); - public abstract void RemoveProject(string filePath); - public abstract void UpdateProject( ProjectKey projectKey, RazorConfiguration? configuration, diff --git a/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/DefaultProjectSnapshotManager.cs b/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/DefaultProjectSnapshotManager.cs index 747e0a0e3e3..7ecbbae4062 100644 --- a/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/DefaultProjectSnapshotManager.cs +++ b/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/DefaultProjectSnapshotManager.cs @@ -4,12 +4,10 @@ using System; using System.Collections.Generic; using System.Collections.Immutable; -using System.Diagnostics; using System.Diagnostics.CodeAnalysis; using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.Razor; -using Microsoft.AspNetCore.Razor.Language; using Microsoft.AspNetCore.Razor.PooledObjects; using Microsoft.AspNetCore.Razor.ProjectSystem; using Microsoft.CodeAnalysis.Razor.Workspaces.ProjectSystem; @@ -446,157 +444,6 @@ protected virtual void NotifyListeners(ProjectChangeEventArgs e) } } - internal override void UpdateProject( - ProjectKey projectKey, - RazorConfiguration configuration, - ProjectWorkspaceState projectWorkspaceState, - string? rootNamespace, - Func> calculate) - { - if (projectWorkspaceState is null) - { - throw new ArgumentNullException(nameof(projectWorkspaceState)); - } - - using var _ = ListPool.GetPooledObject(out var changesToNotify); - - // Get an upgradeableLock, which will keep a read lock while we compute the changes - // and then get a write lock to actually apply them. Only one upgradeable lock - // can be held at any given time. Write lock must be retrieved on the same - // thread that the lock was acquired - using (var upgradeableLock = _rwLocker.EnterUpgradeAbleReadLock()) - { - UpdateProject_NoLock(projectKey, configuration, projectWorkspaceState, rootNamespace, calculate, changesToNotify, upgradeableLock); - } - - // Notify outside of the lock, since notifications may trigger mutations from listeners - foreach (var notification in changesToNotify) - { - NotifyListeners(notification); - } - } - - private void UpdateProject_NoLock( - ProjectKey projectKey, - RazorConfiguration configuration, - ProjectWorkspaceState projectWorkspaceState, - string? rootNamespace, - Func> calculate, - List changesToNotify, - in ReadWriterLocker.UpgradeableReadLock upgradeableLock) - { - var project = GetLoadedProject(projectKey); - if (project is not ProjectSnapshot projectSnapshot) - { - return; - } - - var originalHostProject = projectSnapshot.HostProject; - var changes = calculate(project); - - var originalEntry = _projects_needsLock[projectKey]; - Dictionary updatedProjectsMap = new(changes.Length); - - // Resolve all the changes and add notifications as needed - foreach (var change in changes) - { - switch (change) - { - case AddDocumentAction addAction: - { - var entry = GetCurrentEntry(project); - TryAddNotificationAndUpdate(entry, entry.State.WithAddedHostDocument(addAction.NewDocument, CreateTextAndVersionFunc(addAction.TextLoader)), ProjectChangeKind.DocumentAdded, addAction.NewDocument.FilePath); - } - - break; - - case RemoveDocumentAction removeAction: - { - var entry = GetCurrentEntry(project); - TryAddNotificationAndUpdate(entry, entry.State.WithRemovedHostDocument(removeAction.OriginalDocument), ProjectChangeKind.DocumentRemoved, removeAction.OriginalDocument.FilePath); - } - - break; - - case UpdateDocumentAction updateAction: - { - var entry = GetCurrentEntry(project); - TryAddNotificationAndUpdate(entry, entry.State.WithRemovedHostDocument(updateAction.OriginalDocument), ProjectChangeKind.DocumentRemoved, updateAction.OriginalDocument.FilePath); - - entry = GetCurrentEntry(project); - TryAddNotificationAndUpdate(entry, entry.State.WithAddedHostDocument(updateAction.NewDocument, CreateTextAndVersionFunc(updateAction.TextLoader)), ProjectChangeKind.DocumentAdded, updateAction.NewDocument.FilePath); - } - - break; - - case MoveDocumentAction moveAction: - var (from, to) = (moveAction.OriginalProject, moveAction.DestinationProject); - Debug.Assert(from == project || to == project); - Debug.Assert(from != to); - - var fromEntry = GetCurrentEntry(from); - var toEntry = GetCurrentEntry(to); - - TryAddNotificationAndUpdate(fromEntry, fromEntry.State.WithRemovedHostDocument(moveAction.Document), ProjectChangeKind.DocumentRemoved, moveAction.Document.FilePath); - TryAddNotificationAndUpdate(toEntry, toEntry.State.WithAddedHostDocument(moveAction.Document, CreateTextAndVersionFunc(moveAction.TextLoader)), ProjectChangeKind.DocumentAdded, moveAction.Document.FilePath); - break; - - default: - throw new InvalidOperationException($"Unexpected action type {change.GetType()}"); - } - } - - if (!projectWorkspaceState.Equals(ProjectWorkspaceState.Default)) - { - var entryBeforeWorkspaceState = GetCurrentEntry(project); - var stateWithProjectWorkspaceState = entryBeforeWorkspaceState.State.WithProjectWorkspaceState(projectWorkspaceState); - TryAddNotificationAndUpdate(entryBeforeWorkspaceState, stateWithProjectWorkspaceState, ProjectChangeKind.ProjectChanged, documentFilePath: null); - } - - if (originalHostProject.RootNamespace != rootNamespace || configuration != originalHostProject.Configuration) - { - var currentEntry = GetCurrentEntry(project); - var currentHostProject = currentEntry.State.HostProject; - var newHostProject = new HostProject(currentHostProject.FilePath, currentHostProject.IntermediateOutputPath, configuration, rootNamespace); - var newEntry = new Entry(currentEntry.State.WithHostProject(newHostProject)); - updatedProjectsMap[project.Key] = newEntry; - changesToNotify.Add(new ProjectChangeEventArgs(currentEntry.GetSnapshot(), newEntry.GetSnapshot(), ProjectChangeKind.ProjectChanged)); - } - - // Update current state first so we can get rid of the write lock and downgrade - // back to a read lock when notifying changes - using (upgradeableLock.EnterWriteLock()) - { - foreach (var (path, entry) in updatedProjectsMap) - { - _projects_needsLock[path] = entry; - } - } - - void TryAddNotificationAndUpdate(Entry currentEntry, ProjectState newState, ProjectChangeKind changeKind, string? documentFilePath) - { - if (newState.Equals(currentEntry.State)) - { - return; - } - - var newEntry = new Entry(newState); - updatedProjectsMap[currentEntry.State.HostProject.Key] = newEntry; - changesToNotify.Add(new ProjectChangeEventArgs(currentEntry.GetSnapshot(), newEntry.GetSnapshot(), documentFilePath, changeKind, IsSolutionClosing)); - } - - Entry GetCurrentEntry(IProjectSnapshot project) - { - if (!updatedProjectsMap.TryGetValue(project.Key, out var entry)) - { - entry = _projects_needsLock[project.Key]; - updatedProjectsMap[project.Key] = entry; - } - - return entry; - } - } - private static Func> CreateTextAndVersionFunc(TextLoader textLoader) => textLoader is null ? DocumentState.EmptyLoader diff --git a/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/ProjectSnapshotManagerBase.cs b/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/ProjectSnapshotManagerBase.cs index 3461ac86a08..66323243973 100644 --- a/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/ProjectSnapshotManagerBase.cs +++ b/src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/ProjectSystem/ProjectSnapshotManagerBase.cs @@ -4,9 +4,7 @@ using System; using System.Collections.Immutable; using System.Diagnostics.CodeAnalysis; -using Microsoft.AspNetCore.Razor.Language; using Microsoft.AspNetCore.Razor.ProjectSystem; -using Microsoft.CodeAnalysis.Razor.Workspaces.ProjectSystem; using Microsoft.CodeAnalysis.Text; namespace Microsoft.CodeAnalysis.Razor.ProjectSystem; @@ -55,11 +53,4 @@ internal abstract class ProjectSnapshotManagerBase : ProjectSnapshotManager internal abstract IProjectSnapshot GetOrAddLoadedProject(ProjectKey projectKey, Func createHostProjectFunc); internal abstract bool TryRemoveLoadedProject(ProjectKey projectKey, [NotNullWhen(true)] out IProjectSnapshot? project); - - internal abstract void UpdateProject( - ProjectKey projectKey, - RazorConfiguration configuration, - ProjectWorkspaceState projectWorkspaceState, - string? rootNamespace, - Func> calculateUpdates); } diff --git a/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/Common/BackgroundDocumentGeneratorTest.cs b/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/Common/BackgroundDocumentGeneratorTest.cs deleted file mode 100644 index b46a2c5aa1b..00000000000 --- a/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/Common/BackgroundDocumentGeneratorTest.cs +++ /dev/null @@ -1,148 +0,0 @@ -// Copyright (c) .NET Foundation. All rights reserved. -// Licensed under the MIT license. See License.txt in the project root for license information. - -using System; -using System.Threading; -using System.Threading.Tasks; -using Microsoft.AspNetCore.Razor.Language; -using Microsoft.AspNetCore.Razor.Test.Common; -using Microsoft.CodeAnalysis.Razor; -using Microsoft.CodeAnalysis.Razor.ProjectSystem; -using Xunit; -using Xunit.Abstractions; - -namespace Microsoft.AspNetCore.Razor.LanguageServer.Common; - -// These tests are really integration tests. There isn't a good way to unit test this functionality since -// the only thing in here is threading. -public class BackgroundDocumentGeneratorTest(ITestOutputHelper testOutput) : LanguageServerTestBase(testOutput) -{ - private readonly HostDocument[] _documents = new HostDocument[] - { - new HostDocument("c:/Test1/Index.cshtml", "Index.cshtml"), - new HostDocument("c:/Test1/Components/Counter.cshtml", "Components/Counter.cshtml"), - }; - - private readonly HostProject _hostProject1 = new("c:/Test1/Test1.csproj", "c:/Test1/obj", RazorConfiguration.Default, "TestRootNamespace"); - private readonly HostProject _hostProject2 = new("c:/Test2/Test2.csproj", "c:/Test2/obj", RazorConfiguration.Default, "TestRootNamespace"); - - [Fact] - public async Task Queue_ProcessesNotifications_AndGoesBackToSleep() - { - // Arrange - var projectManager = TestProjectSnapshotManager.Create(ErrorReporter); - await Dispatcher.RunOnDispatcherThreadAsync(() => - { - projectManager.ProjectAdded(_hostProject1); - projectManager.ProjectAdded(_hostProject2); - projectManager.DocumentAdded(_hostProject1.Key, _documents[0], null!); - projectManager.DocumentAdded(_hostProject1.Key, _documents[1], null!); - }, DisposalToken); - - var project = await Dispatcher.RunOnDispatcherThreadAsync( - () => projectManager.GetLoadedProject(_hostProject1.Key), DisposalToken); - - Assert.NotNull(project); - - var queue = new TestBackgroundDocumentGenerator(Dispatcher) - { - Delay = TimeSpan.FromMilliseconds(1), - BlockBackgroundWorkStart = new ManualResetEventSlim(initialState: false), - NotifyBackgroundWorkStarting = new ManualResetEventSlim(initialState: false), - BlockBackgroundWorkCompleting = new ManualResetEventSlim(initialState: false), - NotifyBackgroundWorkCompleted = new ManualResetEventSlim(initialState: false), - }; - - // Act & Assert - await Dispatcher.RunOnDispatcherThreadAsync( - () => queue.Enqueue(project.GetDocument(_documents[0].FilePath).AssumeNotNull()), DisposalToken); - - Assert.True(queue.IsScheduledOrRunning, "Queue should be scheduled during Enqueue"); - Assert.True(queue.HasPendingNotifications, "Queue should have a notification created during Enqueue"); - - // Allow the background work to proceed. - queue.BlockBackgroundWorkStart.Set(); - queue.BlockBackgroundWorkCompleting.Set(); - - queue.NotifyBackgroundWorkCompleted.Wait(TimeSpan.FromSeconds(3)); - - Assert.False(queue.IsScheduledOrRunning, "Queue should not have restarted"); - Assert.False(queue.HasPendingNotifications, "Queue should have processed all notifications"); - } - - [Fact] - public async Task Queue_ProcessesNotifications_AndRestarts() - { - // Arrange - var projectManager = TestProjectSnapshotManager.Create(ErrorReporter); - await Dispatcher.RunOnDispatcherThreadAsync(() => - { - projectManager.ProjectAdded(_hostProject1); - projectManager.ProjectAdded(_hostProject2); - projectManager.DocumentAdded(_hostProject1.Key, _documents[0], null!); - projectManager.DocumentAdded(_hostProject1.Key, _documents[1], null!); - }, DisposalToken); - - var project = await Dispatcher.RunOnDispatcherThreadAsync( - () => projectManager.GetLoadedProject(_hostProject1.Key), DisposalToken); - - Assert.NotNull(project); - - var queue = new TestBackgroundDocumentGenerator(Dispatcher) - { - Delay = TimeSpan.FromMilliseconds(1), - BlockBackgroundWorkStart = new ManualResetEventSlim(initialState: false), - NotifyBackgroundWorkStarting = new ManualResetEventSlim(initialState: false), - NotifyBackgroundCapturedWorkload = new ManualResetEventSlim(initialState: false), - BlockBackgroundWorkCompleting = new ManualResetEventSlim(initialState: false), - NotifyBackgroundWorkCompleted = new ManualResetEventSlim(initialState: false), - }; - - // Act & Assert - await Dispatcher.RunOnDispatcherThreadAsync( - () => queue.Enqueue(project.GetDocument(_documents[0].FilePath).AssumeNotNull()), DisposalToken); - - Assert.True(queue.IsScheduledOrRunning, "Queue should be scheduled during Enqueue"); - Assert.True(queue.HasPendingNotifications, "Queue should have a notification created during Enqueue"); - - // Allow the background work to start. - queue.BlockBackgroundWorkStart.Set(); - - queue.NotifyBackgroundWorkStarting.Wait(TimeSpan.FromSeconds(1)); - Assert.True(queue.IsScheduledOrRunning, "Worker should be processing now"); - - queue.NotifyBackgroundCapturedWorkload.Wait(TimeSpan.FromSeconds(1)); - Assert.False(queue.HasPendingNotifications, "Worker should have taken all notifications"); - - await Dispatcher.RunOnDispatcherThreadAsync( - () => queue.Enqueue(project.GetDocument(_documents[1].FilePath).AssumeNotNull()), DisposalToken); - Assert.True(queue.HasPendingNotifications); // Now we should see the worker restart when it finishes. - - // Allow work to complete, which should restart the timer. - queue.BlockBackgroundWorkCompleting.Set(); - - queue.NotifyBackgroundWorkCompleted.Wait(TimeSpan.FromSeconds(3)); - queue.NotifyBackgroundWorkCompleted.Reset(); - - // It should start running again right away. - Assert.True(queue.IsScheduledOrRunning, "Queue should be scheduled during Enqueue"); - Assert.True(queue.HasPendingNotifications, "Queue should have a notification created during Enqueue"); - - // Allow the background work to proceed. - queue.BlockBackgroundWorkStart.Set(); - - queue.BlockBackgroundWorkCompleting.Set(); - queue.NotifyBackgroundWorkCompleted.Wait(TimeSpan.FromSeconds(3)); - - Assert.False(queue.IsScheduledOrRunning, "Queue should not have restarted"); - Assert.False(queue.HasPendingNotifications, "Queue should have processed all notifications"); - } - - private class TestBackgroundDocumentGenerator : BackgroundDocumentGenerator - { - public TestBackgroundDocumentGenerator(ProjectSnapshotManagerDispatcher projectSnapshotManagerDispatcher) - : base(projectSnapshotManagerDispatcher) - { - } - } -} diff --git a/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/DefaultRazorProjectServiceTest.cs b/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/DefaultRazorProjectServiceTest.cs index 063f9c8f6bf..70de7578c33 100644 --- a/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/DefaultRazorProjectServiceTest.cs +++ b/src/Razor/test/Microsoft.AspNetCore.Razor.LanguageServer.Test/DefaultRazorProjectServiceTest.cs @@ -1010,50 +1010,6 @@ public void AddProject_AddsProjectWithSpecifiedConfiguration() projectSnapshotManager.VerifyAll(); } - [Fact] - public void RemoveProject_RemovesProject() - { - // Arrange - var projectFilePath = "C:/path/to/project.csproj"; - var ownerProject = TestProjectSnapshot.Create("C:/path/to/obj"); - var miscellaneousProject = TestProjectSnapshot.Create("C:/__MISC_PROJECT__"); - var projectResolver = new TestSnapshotResolver(new Dictionary(), miscellaneousProject); - var projectSnapshotManager = new Mock(MockBehavior.Strict); - projectSnapshotManager.Setup(manager => manager.GetLoadedProject(ownerProject.Key)) - .Returns(ownerProject); - projectSnapshotManager - .Setup(p => p.GetAllProjectKeys(projectFilePath)) - .Returns(ImmutableArray.Create(ownerProject.Key)); - projectSnapshotManager.Setup(manager => manager.ProjectRemoved(ownerProject.Key)) - .Callback((projectKey) => Assert.Equal(projectKey, ownerProject.Key)); - var projectService = CreateProjectService(projectResolver, projectSnapshotManager.Object); - - // Act - projectService.RemoveProject(projectFilePath); - - // Assert - projectSnapshotManager.VerifyAll(); - } - - [Fact] - public void RemoveProject_NoopsIfProjectIsNotLoaded() - { - // Arrange - var projectFilePath = "C:/path/to/project.csproj"; - var miscellaneousProject = TestProjectSnapshot.Create("C:/__MISC_PROJECT__"); - var projectResolver = new TestSnapshotResolver(new Dictionary(), miscellaneousProject); - var projectSnapshotManager = new Mock(MockBehavior.Strict); - projectSnapshotManager.Setup(manager => manager.ProjectRemoved(It.IsAny())) - .Throws(new InvalidOperationException("Should not have been called.")); - projectSnapshotManager - .Setup(p => p.GetAllProjectKeys(projectFilePath)) - .Returns(ImmutableArray.Empty); - var projectService = CreateProjectService(projectResolver, projectSnapshotManager.Object); - - // Act & Assert - projectService.RemoveProject(projectFilePath); - } - [Fact] public void TryMigrateDocumentsFromRemovedProject_MigratesDocumentsToNonMiscProject() { diff --git a/src/Razor/test/Microsoft.VisualStudio.LanguageServices.Razor.Test/ProjectSystem/DefaultProjectSnapshotManagerTest.cs b/src/Razor/test/Microsoft.VisualStudio.LanguageServices.Razor.Test/ProjectSystem/DefaultProjectSnapshotManagerTest.cs index 49fe38cfc78..77c23b5faab 100644 --- a/src/Razor/test/Microsoft.VisualStudio.LanguageServices.Razor.Test/ProjectSystem/DefaultProjectSnapshotManagerTest.cs +++ b/src/Razor/test/Microsoft.VisualStudio.LanguageServices.Razor.Test/ProjectSystem/DefaultProjectSnapshotManagerTest.cs @@ -12,7 +12,6 @@ using Microsoft.AspNetCore.Razor.Language; using Microsoft.AspNetCore.Razor.ProjectSystem; using Microsoft.CodeAnalysis.Host; -using Microsoft.CodeAnalysis.Razor.Workspaces.ProjectSystem; using Microsoft.CodeAnalysis.Text; using Moq; using Xunit; @@ -662,194 +661,6 @@ public void SolutionClosing_ProjectChangedEventsCorrect() textLoader.Verify(d => d.LoadTextAndVersionAsync(It.IsAny(), It.IsAny()), Times.Never()); } - [UIFact] - public void UpdateProject_UpdatesCorrectly() - { - // Arrange - _projectManager.ProjectAdded(_hostProject); - _projectManager.ProjectAdded(_hostProject2); - _projectManager.DocumentAdded(_hostProject.Key, _documents[0], null); - _projectManager.DocumentAdded(_hostProject.Key, _documents[1], null); - _projectManager.DocumentAdded(_hostProject.Key, _documents[3], null); - _projectManager.Reset(); - - var projects = _projectManager.GetProjects(); - var project = projects[0]; - var destinationProject = projects[1]; - - var events = new List(); - _projectManager.Changed += (s, e) => events.Add(e); - _projectManager.NotifyChangedEvents = true; - - // Act - _projectManager.UpdateProject( - _hostProject.Key, - FallbackRazorConfiguration.MVC_5_0, - _projectWorkspaceStateWithTagHelpers, - "NewRoot", - snapshot => new IUpdateProjectAction[] - { // Below is what ProjectChangeKind happens for each action, in order - new AddDocumentAction(_documents[4], null), // DocumentAdded - new MoveDocumentAction(snapshot, destinationProject, _documents[1], null), // DocumentRemoved + DocumentAdded - new RemoveDocumentAction(_documents[0]), // DocumentRemoved - new UpdateDocumentAction(_documents[3], _documents[1], null), // DocumentRemoved + DocumentAdded - }.ToImmutableArray()); - - // Assert - - // Assert event ordering and information is as expected - Assert.Collection(events, - e => // AddDocumentAction - { - Assert.Equal(ProjectChangeKind.DocumentAdded, e.Kind); - Assert.Equal(_documents[4].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - - Assert.Collection(e.Older.DocumentFilePaths, - p => Assert.Equal(_documents[1].FilePath, p), - p => Assert.Equal(_documents[0].FilePath, p), - p => Assert.Equal(_documents[3].FilePath, p)); - - Assert.Collection(e.Newer.DocumentFilePaths, - p => Assert.Equal(_documents[1].FilePath, p), - p => Assert.Equal(_documents[0].FilePath, p), - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - }, - e => // MoveDocumentAction:DocumentRemoved - { - Assert.Equal(ProjectChangeKind.DocumentRemoved, e.Kind); - Assert.Equal(_documents[1].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - - Assert.Collection(e.Older.DocumentFilePaths, - p => Assert.Equal(_documents[1].FilePath, p), - p => Assert.Equal(_documents[0].FilePath, p), - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - - Assert.Collection(e.Newer.DocumentFilePaths, - p => Assert.Equal(_documents[0].FilePath, p), - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - }, - e => // MoveDocumentAction:DocumentAdded - { - Assert.Equal(ProjectChangeKind.DocumentAdded, e.Kind); - Assert.Equal(_documents[1].FilePath, e.DocumentFilePath); - Assert.Equal(_documents[1].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject2.Key, e.ProjectKey); - Assert.Equal(_hostProject2.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject2.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject2.FilePath, e.Newer.FilePath); - Assert.Equal(_hostProject2.Key, e.Older.Key); - Assert.Equal(_hostProject2.Key, e.Newer.Key); - - Assert.Empty(e.Older.DocumentFilePaths); - Assert.Collection(e.Newer.DocumentFilePaths, p => Assert.Equal(_documents[1].FilePath, p)); - }, - e => // RemoveDocumentAction - { - Assert.Equal(ProjectChangeKind.DocumentRemoved, e.Kind); - Assert.Equal(_documents[0].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - - Assert.Collection(e.Older.DocumentFilePaths, - p => Assert.Equal(_documents[0].FilePath, p), - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - - Assert.Collection(e.Newer.DocumentFilePaths, - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - }, - e => // UpdateDocumentAction:DocumentRemoved - { - Assert.Equal(ProjectChangeKind.DocumentRemoved, e.Kind); - Assert.Equal(_documents[3].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - - Assert.Collection(e.Older.DocumentFilePaths, - p => Assert.Equal(_documents[3].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - - Assert.Collection(e.Newer.DocumentFilePaths, - p => Assert.Equal(_documents[4].FilePath, p)); - }, - e => // UpdateDocumentAction:DocumentAdded - { - Assert.Equal(ProjectChangeKind.DocumentAdded, e.Kind); - Assert.Equal(_documents[1].FilePath, e.DocumentFilePath); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - - Assert.Collection(e.Older.DocumentFilePaths, - p => Assert.Equal(_documents[4].FilePath, p)); - - Assert.Collection(e.Newer.DocumentFilePaths, - p => Assert.Equal(_documents[1].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - }, - e => // ProjectChanged:WorkspaceState - { - Assert.Equal(ProjectChangeKind.ProjectChanged, e.Kind); - Assert.Equal(_hostProject.RootNamespace, e.Older.RootNamespace); - Assert.Equal(e.Newer.RootNamespace, e.Older.RootNamespace); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - Assert.Equal(project.ProjectWorkspaceState, e.Older.ProjectWorkspaceState); - Assert.Equal(_projectWorkspaceStateWithTagHelpers, e.Newer.ProjectWorkspaceState); - }, - e => // ProjectChanged:RootNamespace - { - Assert.Equal(ProjectChangeKind.ProjectChanged, e.Kind); - Assert.Equal(_hostProject.RootNamespace, e.Older.RootNamespace); - Assert.Equal(_hostProject.Key, e.ProjectKey); - Assert.Equal(_hostProject.FilePath, e.ProjectFilePath); - Assert.Equal(_hostProject.FilePath, e.Older.FilePath); - Assert.Equal(_hostProject.FilePath, e.Newer.FilePath); - Assert.Equal(e.Newer.ProjectWorkspaceState, e.Older.ProjectWorkspaceState); - Assert.Equal("NewRoot", e.Newer.RootNamespace); - }); - - // Assert final state is as expected - Assert.Collection(_projectManager.GetProjects(), - p => - { - Assert.Equal(_hostProject.Key, p.Key); - Assert.Equal(_hostProject.FilePath, p.FilePath); - Assert.Equal("NewRoot", p.RootNamespace); - Assert.Equal(_projectWorkspaceStateWithTagHelpers, p.ProjectWorkspaceState); - Assert.Collection(p.DocumentFilePaths, - p => Assert.Equal(_documents[1].FilePath, p), - p => Assert.Equal(_documents[4].FilePath, p)); - }, - p => - { - Assert.Equal(_hostProject2.Key, p.Key); - Assert.Equal(_hostProject2.FilePath, p.FilePath); - Assert.Equal(_hostProject2.RootNamespace, p.RootNamespace); - Assert.Equal(destinationProject.ProjectWorkspaceState, p.ProjectWorkspaceState); - Assert.Collection(p.DocumentFilePaths, p => Assert.Equal(_documents[1].FilePath, p)); - }); - } - private class TestProjectSnapshotManager : DefaultProjectSnapshotManager { public TestProjectSnapshotManager(IEnumerable triggers, Workspace workspace) From 3534e797771dac3d28964abef4ce0d5dc4346c5e Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 10:48:14 +1000 Subject: [PATCH 02/13] Add some clarity to the logs Logging the project key intead of the filename makes it easier to understand what is going on. For the configuration state change, since the changes are debounced, it wasn't clear when any event would actually be applied. --- .../ProjectConfigurationStateSynchronizer.cs | 2 ++ .../DefaultRazorProjectService.cs | 30 +++++++++---------- .../RazorRequestContextFactory.cs | 5 ++-- 3 files changed, 20 insertions(+), 17 deletions(-) diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectConfigurationStateSynchronizer.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectConfigurationStateSynchronizer.cs index f28c3f0c49a..d3e544e1513 100644 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectConfigurationStateSynchronizer.cs +++ b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectConfigurationStateSynchronizer.cs @@ -139,6 +139,8 @@ void UpdateProject(ProjectKey projectKey, RazorProjectInfo? projectInfo) return; } + _logger.LogInformation("Actually updating {project} with a real projectInfo", projectKey); + var projectWorkspaceState = projectInfo.ProjectWorkspaceState ?? ProjectWorkspaceState.Default; var documents = projectInfo.Documents; _projectService.UpdateProject( diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs index 703abb8eb83..fb10a7a4a23 100644 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs +++ b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/ProjectSystem/DefaultRazorProjectService.cs @@ -253,7 +253,7 @@ public override ProjectKey AddProject(string filePath, string intermediateOutput // ProjectAdded will no-op if the project already exists _projectSnapshotManagerAccessor.Instance.ProjectAdded(hostProject); - _logger.LogInformation("Added project '{filePath}' to project system.", filePath); + _logger.LogInformation("Added project '{filePath}' with key {key} to project system.", filePath, hostProject.Key); TryMigrateMiscellaneousDocumentsToProject(); @@ -282,8 +282,8 @@ public override void UpdateProject( if (!projectWorkspaceState.Equals(ProjectWorkspaceState.Default)) { - _logger.LogInformation("Updating project '{filePath}' TagHelpers ({projectWorkspaceState.TagHelpers.Count}) and C# Language Version ({projectWorkspaceState.CSharpLanguageVersion}).", - project.FilePath, projectWorkspaceState.TagHelpers.Length, projectWorkspaceState.CSharpLanguageVersion); + _logger.LogInformation("Updating project '{key}' TagHelpers ({projectWorkspaceState.TagHelpers.Count}) and C# Language Version ({projectWorkspaceState.CSharpLanguageVersion}).", + project.Key, projectWorkspaceState.TagHelpers.Length, projectWorkspaceState.CSharpLanguageVersion); } _projectSnapshotManagerAccessor.Instance.ProjectWorkspaceStateChanged(project.Key, projectWorkspaceState); @@ -293,25 +293,25 @@ public override void UpdateProject( if (currentConfiguration.ConfigurationName == configuration?.ConfigurationName && currentHostProject.RootNamespace == rootNamespace) { - _logger.LogTrace("Updating project '{filePath}'. The project is already using configuration '{configuration.ConfigurationName}' and root namespace '{rootNamespace}'.", - project.FilePath, configuration.ConfigurationName, rootNamespace); + _logger.LogTrace("Updating project '{key}'. The project is already using configuration '{configuration.ConfigurationName}' and root namespace '{rootNamespace}'.", + project.Key, configuration.ConfigurationName, rootNamespace); return; } if (configuration is null) { configuration = FallbackRazorConfiguration.Latest; - _logger.LogInformation("Updating project '{filePath}' to use the latest configuration ('{configuration.ConfigurationName}')'.", project.FilePath, configuration.ConfigurationName); + _logger.LogInformation("Updating project '{key}' to use the latest configuration ('{configuration.ConfigurationName}')'.", project.Key, configuration.ConfigurationName); } else if (currentConfiguration.ConfigurationName != configuration.ConfigurationName) { - _logger.LogInformation("Updating project '{filePath}' to Razor configuration '{configuration.ConfigurationName}' with language version '{configuration.LanguageVersion}'.", - project.FilePath, configuration.ConfigurationName, configuration.LanguageVersion); + _logger.LogInformation("Updating project '{key}' to Razor configuration '{configuration.ConfigurationName}' with language version '{configuration.LanguageVersion}'.", + project.Key, configuration.ConfigurationName, configuration.LanguageVersion); } if (currentHostProject.RootNamespace != rootNamespace) { - _logger.LogInformation("Updating project '{filePath}''s root namespace to '{rootNamespace}'.", project.FilePath, rootNamespace); + _logger.LogInformation("Updating project '{key}''s root namespace to '{rootNamespace}'.", project.Key, rootNamespace); } var hostProject = new HostProject(project.FilePath, project.IntermediateOutputPath, configuration, rootNamespace); @@ -401,7 +401,7 @@ private void UpdateProjectDocuments(IReadOnlyList docume var remoteTextLoader = _remoteTextLoaderFactory.Create(documentFilePath); var newHostDocument = new HostDocument(documentFilePath, documentHandle.TargetPath, documentHandle.FileKind); - _logger.LogInformation("Adding new document '{documentFilePath}' to project '{projectFilePath}'.", documentFilePath, currentHostProject.FilePath); + _logger.LogInformation("Adding new document '{documentFilePath}' to project '{key}'.", documentFilePath, currentHostProject.Key); _projectSnapshotManagerAccessor.Instance.DocumentAdded(currentHostProject.Key, newHostDocument, remoteTextLoader); } } @@ -422,8 +422,8 @@ private void MoveDocument(string documentFilePath, IProjectSnapshot fromProject, var textLoader = new DocumentSnapshotTextLoader(documentSnapshot); var newHostDocument = new HostDocument(documentSnapshot.FilePath, documentSnapshot.TargetPath, documentSnapshot.FileKind); - _logger.LogInformation("Moving '{documentFilePath}' from the '{fromProject.FilePath}' project to '{toProject.FilePath}' project.", - documentFilePath, fromProject.FilePath, toProject.FilePath); + _logger.LogInformation("Moving '{documentFilePath}' from the '{fromProject.Key}' project to '{toProject.Key}' project.", + documentFilePath, fromProject.Key, toProject.Key); _projectSnapshotManagerAccessor.Instance.DocumentRemoved(fromProject.Key, currentHostDocument); _projectSnapshotManagerAccessor.Instance.DocumentAdded(toProject.Key, newHostDocument, textLoader); } @@ -461,8 +461,8 @@ internal void TryMigrateDocumentsFromRemovedProject(IProjectSnapshot project) var defaultToProject = (ProjectSnapshot)toProject; var newHostDocument = new HostDocument(documentSnapshot.FilePath, documentSnapshot.TargetPath, documentSnapshot.FileKind); - _logger.LogInformation("Migrating '{documentFilePath}' from the '{project.FilePath}' project to '{toProject.FilePath}' project.", - documentFilePath, project.FilePath, toProject.FilePath); + _logger.LogInformation("Migrating '{documentFilePath}' from the '{project.Key}' project to '{toProject.KEy}' project.", + documentFilePath, project.Key, toProject.Key); _projectSnapshotManagerAccessor.Instance.DocumentAdded(defaultToProject.Key, newHostDocument, textLoader); } } @@ -497,7 +497,7 @@ internal void TryMigrateMiscellaneousDocumentsToProject() var defaultProject = (ProjectSnapshot)projectSnapshot; var newHostDocument = new HostDocument(documentSnapshot.FilePath, documentSnapshot.TargetPath); _logger.LogInformation("Migrating '{documentFilePath}' from the '{miscellaneousProject.Key}' project to '{projectSnapshot.Key}' project.", - documentFilePath, miscellaneousProject.FilePath, projectSnapshot.Key); + documentFilePath, miscellaneousProject.Key, projectSnapshot.Key); _projectSnapshotManagerAccessor.Instance.DocumentAdded(defaultProject.Key, newHostDocument, textLoader); } } diff --git a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/RazorRequestContextFactory.cs b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/RazorRequestContextFactory.cs index abb7a3a3f42..16d78f6401a 100644 --- a/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/RazorRequestContextFactory.cs +++ b/src/Razor/src/Microsoft.AspNetCore.Razor.LanguageServer/RazorRequestContextFactory.cs @@ -5,6 +5,7 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.Razor.LanguageServer.EndpointContracts; +using Microsoft.AspNetCore.Razor.LanguageServer.Extensions; using Microsoft.CommonLanguageServerProtocol.Framework; using Microsoft.VisualStudio.LanguageServer.Protocol; @@ -35,7 +36,7 @@ public Task CreateRequestContextAsync(IQueu var textDocumentIdentifier = tdiHandler.GetTextDocumentIdentifier(@params); uri = textDocumentIdentifier.Uri; - logger.LogDebug("Trying to create DocumentContext for {methodName} for {uri}", queueItem.MethodName, uri); + logger.LogDebug("Trying to create DocumentContext for {methodName} for {projectContext} for {uri}", queueItem.MethodName, textDocumentIdentifier.GetProjectContext()?.Id ?? "(no project context)", uri); documentContext = documentContextFactory.TryCreateForOpenDocument(textDocumentIdentifier); } @@ -43,7 +44,7 @@ public Task CreateRequestContextAsync(IQueu { uri = uriHandler.GetTextDocumentIdentifier(@params); - logger.LogDebug("Trying to create DocumentContext for {methodName} for {uri}", queueItem.MethodName, uri); + logger.LogDebug("Trying to create DocumentContext for {methodName}, with no project context, for {uri}", queueItem.MethodName, uri); documentContext = documentContextFactory.TryCreateForOpenDocument(uri); } From e66b53a60dc0915a296f4e6e2d38c100170f33df Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 10:52:25 +1000 Subject: [PATCH 03/13] Wait for LogHub logs to be written before copying This seems to resolve the issue with the zip file being corrupted. Also included more log files because I wasn't convinced we were getting them all --- .../VisualStudioLogging.cs | 75 +++++++++++++++---- 1 file changed, 61 insertions(+), 14 deletions(-) diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/VisualStudioLogging.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/VisualStudioLogging.cs index 59f9b3579cf..6172ec66877 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/VisualStudioLogging.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/VisualStudioLogging.cs @@ -61,7 +61,7 @@ private static void RazorMEFErrorLogger(string filePath) private static void RazorLogHubLogger(string filePath) { - FeedbackLoggerInternal(filePath, "LogHub"); + FeedbackLoggerInternal(filePath, "LogHub", "Razor"); } private static void RazorServiceHubLogger(string filePath) @@ -74,7 +74,7 @@ private static void RazorComponentModelCacheLogger(string filePath) FeedbackLoggerInternal(filePath, "ComponentModelCache"); } - private static void FeedbackLoggerInternal(string filePath, string expectedFilePart) + private static void FeedbackLoggerInternal(string filePath, params string[] expectedFileParts) { var componentModel = GlobalServiceProvider.ServiceProvider.GetService(); if (componentModel is null) @@ -92,7 +92,7 @@ private static void FeedbackLoggerInternal(string filePath, string expectedFileP files.AddRange(feedbackFileProvider.GetFiles()); } - _ = CollectFeedbackItemsAsync(files, filePath, expectedFilePart); + _ = CollectFeedbackItemsAsync(files, filePath, expectedFileParts); } private static void RazorExtensionExplorerLogger(string filePath) @@ -181,7 +181,7 @@ private static void RazorOutputPaneLogger(string filePath) }); } - private static async Task CollectFeedbackItemsAsync(IEnumerable files, string destination, string expectedFilePart) + private static async Task CollectFeedbackItemsAsync(IEnumerable files, string destination, string[] expectedFileParts) { // What's important in this weird threading stuff is ensuring we vacate the thread RazorLogHubLogger was called on // because if we don't it ends up blocking the thread that creates the zip file we need. @@ -191,18 +191,25 @@ await ThreadHelper.JoinableTaskFactory.RunAsync(async () => { var name = Path.GetFileName(file); - // Only capture LogHub - if (name.Contains(expectedFilePart) && Path.GetExtension(file) == ".zip") + if (!Path.GetExtension(file).Equals(".zip", StringComparison.OrdinalIgnoreCase)) { - await Task.Run(() => - { - WaitForFileExists(file); - if (File.Exists(file)) - { - File.Copy(file, destination); - } - }); + continue; + } + + if (expectedFileParts.All(part => name.IndexOf(part, StringComparison.OrdinalIgnoreCase) == -1)) + { + continue; } + + await Task.Run(() => + { + WaitForFileExists(file); + WaitForFileFinishedWriting(file); + if (File.Exists(file)) + { + File.Copy(file, destination); + } + }); } }); } @@ -220,4 +227,44 @@ private static void WaitForFileExists(string file) Thread.Sleep(100); } } + + private static void WaitForFileFinishedWriting(string file) + { + const int MaxRetries = 50; + var retries = 0; + while (IsFileLocked(file) && retries < MaxRetries) + { + retries++; + // Free your thread + Thread.Yield(); + // Wait a bit + Thread.Sleep(100); + } + } + + private static bool IsFileLocked(string file) + { + FileStream? stream = null; + + try + { + stream = File.Open(file, FileMode.Open, FileAccess.ReadWrite, FileShare.None); + } + catch (IOException) + { + //the file is unavailable because it is: + //still being written to + //or being processed by another thread + //or does not exist (has already been processed) + return true; + } + finally + { + if (stream != null) + stream.Close(); + } + + //file is not locked + return false; + } } From a7bc2018390e3f6a778d6a4788c69a4e83ef4b48 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 10:52:51 +1000 Subject: [PATCH 04/13] Wait for language server during project unload/reload --- .../InProcess/RazorProjectSystemInProcess.cs | 19 +++++++++++++++++++ .../ProjectTests.cs | 4 ++++ 2 files changed, 23 insertions(+) diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/RazorProjectSystemInProcess.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/RazorProjectSystemInProcess.cs index a0550b3d1c1..72abf93038f 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/RazorProjectSystemInProcess.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/RazorProjectSystemInProcess.cs @@ -15,6 +15,25 @@ namespace Microsoft.VisualStudio.Extensibility.Testing; [TestService] internal partial class RazorProjectSystemInProcess { + public async Task WaitForLSPServerActivatedAsync(CancellationToken cancellationToken) + { + await WaitForLSPServerActivationStatusAsync(active: true, cancellationToken); + } + + public async Task WaitForLSPServerDeactivatedAsync(CancellationToken cancellationToken) + { + await WaitForLSPServerActivationStatusAsync(active: false, cancellationToken); + } + + private async Task WaitForLSPServerActivationStatusAsync(bool active, CancellationToken cancellationToken) + { + var tracker = await TestServices.Shell.GetComponentModelServiceAsync(cancellationToken); + await Helper.RetryAsync(ct => + { + return Task.FromResult(tracker.IsActive == active); + }, TimeSpan.FromMilliseconds(50), cancellationToken); + } + public async Task WaitForProjectFileAsync(string projectFilePath, CancellationToken cancellationToken) { var accessor = await TestServices.Shell.GetComponentModelServiceAsync(cancellationToken); diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs index f0665aedc87..a035945fbad 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs @@ -73,6 +73,8 @@ public async Task MultiTargetProject() // CPS doesn't support changing from single targeting to multi-targeting while a project is open await TestServices.SolutionExplorer.CloseSolutionAsync(ControlledHangMitigatingCancellationToken); + await TestServices.RazorProjectSystem.WaitForLSPServerDeactivatedAsync(ControlledHangMitigatingCancellationToken); + var sb = new StringBuilder(); foreach (var line in File.ReadAllLines(projectFileName)) { @@ -100,6 +102,8 @@ public async Task MultiTargetProject() // way we know the LSP server is up, running, and has processed both local and library-sourced Components await TestServices.SolutionExplorer.OpenFileAsync(RazorProjectConstants.BlazorProjectName, RazorProjectConstants.IndexRazorFile, ControlledHangMitigatingCancellationToken); + await TestServices.RazorProjectSystem.WaitForLSPServerActivatedAsync(ControlledHangMitigatingCancellationToken); + await TestServices.Workspace.WaitForProjectSystemAsync(ControlledHangMitigatingCancellationToken); await TestServices.Editor.PlaceCaretAsync("", charsOffset: 1, ControlledHangMitigatingCancellationToken); From d2535e4b35a0e63f2c8e2c381c189f0c145a2867 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 10:54:48 +1000 Subject: [PATCH 05/13] Attach test specific logging to the output window logging Now that the output window uses a queue, to avoid threading issues, we were missing some logs as tests fail. This allows our integration tests to hook into the output window logging and ensure we capture it all directly into the test output. What this means in practice is being able to download the one test run log file, and have it contain the full log for any failing test. --- .../Logging/IOutputWindowLogger.cs | 1 + .../Logging/OutputWindowLogger.cs | 9 +++++ .../CSharpVirtualDocumentFactoryTest.cs | 4 +++ .../RazorCustomMessageTargetTest.cs | 4 +++ .../AbstractRazorEditorTest.cs | 12 +++++-- .../InProcess/OutputInProcess.cs | 22 +++++++++++++ .../LogIntegrationTestAttribute.cs | 33 +++++++++++++++++++ 7 files changed, 83 insertions(+), 2 deletions(-) create mode 100644 src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/LogIntegrationTestAttribute.cs diff --git a/src/Razor/src/Microsoft.VisualStudio.Editor.Razor/Logging/IOutputWindowLogger.cs b/src/Razor/src/Microsoft.VisualStudio.Editor.Razor/Logging/IOutputWindowLogger.cs index 82f63291d72..c7a37d610d8 100644 --- a/src/Razor/src/Microsoft.VisualStudio.Editor.Razor/Logging/IOutputWindowLogger.cs +++ b/src/Razor/src/Microsoft.VisualStudio.Editor.Razor/Logging/IOutputWindowLogger.cs @@ -7,4 +7,5 @@ namespace Microsoft.VisualStudio.Editor.Razor.Logging; internal interface IOutputWindowLogger : ILogger { + void SetTestLogger(ILogger? testOutputLogger); } diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServices.Razor/Logging/OutputWindowLogger.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServices.Razor/Logging/OutputWindowLogger.cs index 7d87169c88b..d03a8475fd2 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServices.Razor/Logging/OutputWindowLogger.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServices.Razor/Logging/OutputWindowLogger.cs @@ -26,6 +26,8 @@ internal class OutputWindowLogger : IOutputWindowLogger, IDisposable private readonly OutputPane _outputPane; + private ILogger? _testLogger; + [ImportingConstructor] public OutputWindowLogger(JoinableTaskContext joinableTaskContext) { @@ -34,6 +36,11 @@ public OutputWindowLogger(JoinableTaskContext joinableTaskContext) public IDisposable BeginScope(TState state) => Scope.Instance; + public void SetTestLogger(ILogger? testLogger) + { + _testLogger = testLogger; + } + public void Dispose() { _outputPane.Dispose(); @@ -46,6 +53,8 @@ public bool IsEnabled(LogLevel logLevel) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) { + _testLogger?.Log(logLevel, eventId, state, exception, formatter); + if (IsEnabled(logLevel)) { _outputPane.WriteLine(DateTime.Now.ToString("h:mm:ss.fff ") + formatter(state, exception)); diff --git a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/CSharpVirtualDocumentFactoryTest.cs b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/CSharpVirtualDocumentFactoryTest.cs index 6cdf14ca2e6..d458d1a4cf3 100644 --- a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/CSharpVirtualDocumentFactoryTest.cs +++ b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/CSharpVirtualDocumentFactoryTest.cs @@ -148,5 +148,9 @@ public bool IsEnabled(LogLevel logLevel) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) { } + + public void SetTestLogger(ILogger testOutputLogger) + { + } } } diff --git a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs index e7d7902ffef..06639cbd4fb 100644 --- a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs +++ b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs @@ -562,5 +562,9 @@ public bool IsEnabled(LogLevel logLevel) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) { } + + public void SetTestLogger(ILogger testOutputLogger) + { + } } } diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/AbstractRazorEditorTest.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/AbstractRazorEditorTest.cs index 367c717783b..6625d7a288b 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/AbstractRazorEditorTest.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/AbstractRazorEditorTest.cs @@ -16,6 +16,7 @@ namespace Microsoft.VisualStudio.Razor.IntegrationTests; +[LogIntegrationTest] public abstract class AbstractRazorEditorTest(ITestOutputHelper testOutputHelper) : AbstractIntegrationTest { private const string LegacyRazorEditorFeatureFlag = "Razor.LSP.LegacyEditor"; @@ -27,6 +28,10 @@ public override async Task InitializeAsync() { await base.InitializeAsync(); + await TestServices.Output.SetupIntegrationTestLoggerAsync(_testOutputHelper, ControlledHangMitigatingCancellationToken); + + await TestServices.Output.LogStatusAsync("#### Razor integration test initialize.", ControlledHangMitigatingCancellationToken); + VisualStudioLogging.AddCustomLoggers(); var projectFilePath = await CreateAndOpenBlazorProjectAsync(ControlledHangMitigatingCancellationToken); @@ -63,6 +68,8 @@ public override async Task InitializeAsync() // Close the file we opened, just in case, so the test can start with a clean slate await TestServices.Editor.CloseCodeFileAsync(RazorProjectConstants.BlazorProjectName, RazorProjectConstants.IndexRazorFile, saveFile: false, ControlledHangMitigatingCancellationToken); + + await TestServices.Output.LogStatusAsync("#### Razor integration test initialize finished.", ControlledHangMitigatingCancellationToken); } private async Task CreateAndOpenBlazorProjectAsync(CancellationToken cancellationToken) @@ -93,8 +100,9 @@ private static string CreateTemporaryPath() public override async Task DisposeAsync() { - var paneContent = await TestServices.Output.GetRazorOutputPaneContentAsync(CancellationToken.None); - _testOutputHelper.WriteLine($"Razor Output Pane Content:{Environment.NewLine}{paneContent}"); + await TestServices.Output.LogStatusAsync("#### Razor integration test dispose.", ControlledHangMitigatingCancellationToken); + + await TestServices.Output.ClearIntegrationTestLoggerAsync(ControlledHangMitigatingCancellationToken); await base.DisposeAsync(); } diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/OutputInProcess.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/OutputInProcess.cs index 13d97d7cd8a..3b2cf529c48 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/OutputInProcess.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/OutputInProcess.cs @@ -4,10 +4,14 @@ using System; using System.Threading; using System.Threading.Tasks; +using Microsoft.AspNetCore.Razor.Test.Common.Logging; +using Microsoft.Extensions.Logging; +using Microsoft.VisualStudio.Editor.Razor.Logging; using Microsoft.VisualStudio.Razor.IntegrationTests.Extensions; using Microsoft.VisualStudio.Shell; using Microsoft.VisualStudio.Shell.Interop; using Microsoft.VisualStudio.TextManager.Interop; +using Xunit.Abstractions; namespace Microsoft.VisualStudio.Extensibility.Testing; @@ -16,6 +20,24 @@ internal partial class OutputInProcess { private const string RazorPaneName = "Razor Logger Output"; + public async Task SetupIntegrationTestLoggerAsync(ITestOutputHelper testOutputHelper, CancellationToken cancellationToken) + { + var logger = await TestServices.Shell.GetComponentModelServiceAsync(cancellationToken); + logger.SetTestLogger(new TestOutputLogger(testOutputHelper)); + } + + public async Task ClearIntegrationTestLoggerAsync(CancellationToken cancellationToken) + { + var logger = await TestServices.Shell.GetComponentModelServiceAsync(cancellationToken); + logger.SetTestLogger(null); + } + + public async Task LogStatusAsync(string message, CancellationToken cancellationToken) + { + var logger = await TestServices.Shell.GetComponentModelServiceAsync(cancellationToken); + logger.LogInformation(message); + } + public async Task HasErrorsAsync(CancellationToken cancellationToken) { var content = await GetRazorOutputPaneContentAsync(cancellationToken); diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/LogIntegrationTestAttribute.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/LogIntegrationTestAttribute.cs new file mode 100644 index 00000000000..39001507a32 --- /dev/null +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/LogIntegrationTestAttribute.cs @@ -0,0 +1,33 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the MIT license. See License.txt in the project root for license information. + +using System; +using System.Reflection; +using Microsoft.Extensions.Logging; +using Microsoft.VisualStudio.ComponentModelHost; +using Microsoft.VisualStudio.Editor.Razor.Logging; +using Microsoft.VisualStudio.Shell; +using Xunit.Sdk; + +namespace Microsoft.VisualStudio.Razor.IntegrationTests; + +[AttributeUsage(AttributeTargets.Class | AttributeTargets.Method, AllowMultiple = false, Inherited = true)] +public class LogIntegrationTestAttribute : BeforeAfterTestAttribute +{ + public override void Before(MethodInfo methodUnderTest) + { + GetLogger().LogInformation("#### Integration test start: {method}", methodUnderTest.Name); + } + + public override void After(MethodInfo methodUnderTest) + { + GetLogger().LogInformation("#### Integration test end: {method}", methodUnderTest.Name); + } + + private static IOutputWindowLogger GetLogger() + { + var componentModel = ServiceProvider.GlobalProvider.GetService(); + var logger = componentModel.GetService(); + return logger; + } +} From f136fd293365fb298530d75228c3cd0bab01d299 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:01:39 +1000 Subject: [PATCH 06/13] Thread cancellation through code actions a bit better It looks like sometimes web tools hangs on getting code actions, but when that happens instead of just one test failing, the whole run would have to wait 20 minutes, then time out. This made identifying the failure much more difficult. Hopefully this helps, if it doesn't, we'll probably need to add our own timeout. --- .../Endpoints/CodeActions.cs | 17 +++++++++++------ .../InProcess/LightBulbHelper.cs | 2 +- 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/CodeActions.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/CodeActions.cs index 53476b8057f..377de484162 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/CodeActions.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/CodeActions.cs @@ -37,7 +37,7 @@ internal partial class RazorCustomMessageTarget (synchronized, virtualDocumentSnapshot) = await TrySynchronizeVirtualDocumentAsync( codeActionParams.HostDocumentVersion, codeActionParams.CodeActionParams.TextDocument, - cancellationToken); + cancellationToken).ConfigureAwait(false); languageServerName = RazorLSPConstants.RazorCSharpLanguageServerName; } else if (codeActionParams.LanguageKind == RazorLanguageKind.CSharp) @@ -45,7 +45,7 @@ internal partial class RazorCustomMessageTarget (synchronized, virtualDocumentSnapshot) = await TrySynchronizeVirtualDocumentAsync( codeActionParams.HostDocumentVersion, codeActionParams.CodeActionParams.TextDocument, - cancellationToken); + cancellationToken).ConfigureAwait(false); languageServerName = RazorLSPConstants.HtmlLanguageServerName; } else @@ -73,8 +73,13 @@ internal partial class RazorCustomMessageTarget cancellationToken).ConfigureAwait(false); var codeActions = new List(); - await foreach (var response in requests) + await foreach (var response in requests.WithCancellation(cancellationToken).ConfigureAwait(false)) { + if (cancellationToken.IsCancellationRequested) + { + break; + } + if (response.Response != null) { codeActions.AddRange(response.Response); @@ -107,7 +112,7 @@ internal partial class RazorCustomMessageTarget (synchronized, virtualDocumentSnapshot) = await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync( resolveCodeActionParams.HostDocumentVersion, resolveCodeActionParams.Uri, - cancellationToken); + cancellationToken).ConfigureAwait(false); } else if (resolveCodeActionParams.LanguageKind == RazorLanguageKind.CSharp) { @@ -115,7 +120,7 @@ internal partial class RazorCustomMessageTarget (synchronized, virtualDocumentSnapshot) = await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync( resolveCodeActionParams.HostDocumentVersion, resolveCodeActionParams.Uri, - cancellationToken); + cancellationToken).ConfigureAwait(false); } else { @@ -138,7 +143,7 @@ internal partial class RazorCustomMessageTarget codeAction, cancellationToken).ConfigureAwait(false); - await foreach (var response in requests) + await foreach (var response in requests.WithCancellation(cancellationToken).ConfigureAwait(false)) { if (response.Response is not null) { diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/LightBulbHelper.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/LightBulbHelper.cs index 8cc7e6457d0..c59276236b1 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/LightBulbHelper.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/InProcess/LightBulbHelper.cs @@ -84,7 +84,7 @@ void Handler(object s, SuggestedActionsUpdatedArgs e) // Calling PopulateWithDataAsync ensures the underlying session will call SuggestedActionsUpdated at least once // with the latest data computed. This is needed so that if the lightbulb computation is already complete // that we hear about the results. - await asyncSession.PopulateWithDataAsync(overrideRequestedActionCategories: null, operationContext: null).ConfigureAwait(false); + await asyncSession.PopulateWithDataAsync(overrideRequestedActionCategories: null, operationContext: null).WithCancellation(cancellationToken).ConfigureAwait(false); return await tcs.Task.WithCancellation(cancellationToken); } From ac071dd7d7fdc69baded1733b628e99face9acfa Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:03:56 +1000 Subject: [PATCH 07/13] Tweak semantic tokens The custom message target infra in the platform doesn't support partial results, and we were getting multiple semantic tokens requests that seems like maybe they overlapped. Both of these are purely speculative changes --- .../Endpoints/SemanticTokens.cs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/SemanticTokens.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/SemanticTokens.cs index 36c42bc9a22..4c336a9343e 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/SemanticTokens.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/SemanticTokens.cs @@ -49,13 +49,15 @@ internal partial class RazorCustomMessageTarget var newParams = new SemanticTokensRangeParams { TextDocument = semanticTokensParams.TextDocument, - PartialResultToken = semanticTokensParams.PartialResultToken, Range = semanticTokensParams.Range, }; var textBuffer = csharpDoc.Snapshot.TextBuffer; var languageServerName = RazorLSPConstants.RazorCSharpLanguageServerName; var lspMethodName = Methods.TextDocumentSemanticTokensRangeName; + + cancellationToken.ThrowIfCancellationRequested(); + using var _ = _telemetryReporter.TrackLspRequest(lspMethodName, languageServerName, semanticTokensParams.CorrelationId); var csharpResults = await _requestInvoker.ReinvokeRequestOnServerAsync( textBuffer, From 96c5ef4dd38d1dcfe081d95772ec4cbf4b22d3d9 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:05:31 +1000 Subject: [PATCH 08/13] Fix typo --- .../RazorLanguageServerClient.cs | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs index 8128e11183b..2df83bba33a 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs @@ -210,9 +210,9 @@ public RazorLanguageServerClient( return connection; } - internal static IEnumerable> GetReleventContainedLanguageClientsAndMetadata(ILanguageServiceBroker2 languageServiceBroker) + internal static IEnumerable> GetRelevantContainedLanguageClientsAndMetadata(ILanguageServiceBroker2 languageServiceBroker) { - var releventClientAndMetadata = new List>(); + var relevantClientAndMetadata = new List>(); #pragma warning disable CS0618 // Type or member is obsolete foreach (var languageClientAndMetadata in languageServiceBroker.LanguageClients) @@ -232,11 +232,11 @@ public RazorLanguageServerClient( if (IsCSharpApplicable(metadata) || metadata.ContentTypes.Contains(RazorLSPConstants.HtmlLSPDelegationContentTypeName)) { - releventClientAndMetadata.Add(languageClientAndMetadata); + relevantClientAndMetadata.Add(languageClientAndMetadata); } } - return releventClientAndMetadata; + return relevantClientAndMetadata; static bool IsCSharpApplicable(ILanguageClientMetadata metadata) { @@ -247,11 +247,11 @@ static bool IsCSharpApplicable(ILanguageClientMetadata metadata) private async Task EnsureContainedLanguageServersInitializedAsync() { - var releventClientsAndMetadata = GetReleventContainedLanguageClientsAndMetadata(_languageServiceBroker); + var relevantClientsAndMetadata = GetRelevantContainedLanguageClientsAndMetadata(_languageServiceBroker); var clientLoadTasks = new List(); - foreach (var languageClientAndMetadata in releventClientsAndMetadata) + foreach (var languageClientAndMetadata in relevantClientsAndMetadata) { if (languageClientAndMetadata.Metadata is not ILanguageClientMetadata metadata) { From c0e67c47fdda5216851f0e444c54120a5043486a Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:05:40 +1000 Subject: [PATCH 09/13] Include as many logs as possible --- azure-pipelines-integration-dartlab.yml | 2 ++ azure-pipelines.yml | 4 ++++ 2 files changed, 6 insertions(+) diff --git a/azure-pipelines-integration-dartlab.yml b/azure-pipelines-integration-dartlab.yml index 525f6a6ee1c..eedc4403ec1 100644 --- a/azure-pipelines-integration-dartlab.yml +++ b/azure-pipelines-integration-dartlab.yml @@ -33,6 +33,8 @@ variables: value: 'true' - name: LogLevel value: 'Verbose' +- name: RAZOR_TRACE + value: 'Verbose' stages: - template: \stages\visual-studio\agent.yml@DartLabTemplates diff --git a/azure-pipelines.yml b/azure-pipelines.yml index 3a4edeb3acf..69cbfefc01d 100644 --- a/azure-pipelines.yml +++ b/azure-pipelines.yml @@ -12,6 +12,10 @@ variables: value: true - name: Codeql.Enabled value: true +- name: LogLevel + value: 'Verbose' +- name: RAZOR_TRACE + value: 'Verbose' - ${{ if ne(variables['System.TeamProject'], 'public') }}: - group: DotNetBuilds storage account read tokens - name: _InternalRuntimeDownloadArgs From bdaf4679527436e17c9785df9235f42438ed920a Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:17:39 +1000 Subject: [PATCH 10/13] Include custom message target logs in LogHub --- .../Endpoints/Diagnostics.cs | 2 +- .../Endpoints/UpdateCSharpBuffer.cs | 12 ++++----- .../RazorCustomMessageTarget.cs | 26 ++++++++++--------- .../RazorLanguageServerClient.cs | 11 ++++++++ .../RazorCustomMessageTargetTest.cs | 24 +++++++---------- 5 files changed, 41 insertions(+), 34 deletions(-) diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/Diagnostics.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/Diagnostics.cs index 10cfbe4802b..d2bf973a388 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/Diagnostics.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/Diagnostics.cs @@ -44,7 +44,7 @@ internal partial class RazorCustomMessageTarget { if (e is not OperationCanceledException) { - _outputWindowLogger?.LogError(e, "Exception thrown in PullDiagnostic delegation"); + _logger?.LogError(e, "Exception thrown in PullDiagnostic delegation"); } // Return null if any of the tasks getting diagnostics results in an error return null; diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/UpdateCSharpBuffer.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/UpdateCSharpBuffer.cs index 61861640c19..046bf764cb2 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/UpdateCSharpBuffer.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/Endpoints/UpdateCSharpBuffer.cs @@ -40,7 +40,7 @@ internal async Task UpdateCSharpBufferCoreAsync(UpdateBufferRequest request, Can var hostDocumentUri = new Uri(request.HostDocumentFilePath); - _outputWindowLogger?.LogDebug("UpdateCSharpBuffer for {version} of {uri} in {projectKey}", request.HostDocumentVersion.Value, hostDocumentUri, request.ProjectKeyId); + _logger?.LogDebug("UpdateCSharpBuffer for {version} of {uri} in {projectKey}", request.HostDocumentVersion.Value, hostDocumentUri, request.ProjectKeyId); // If we're generating unique file paths for virtual documents, then we have to take a different path here, and do more work if (_languageServerFeatureOptions.IncludeProjectKeyInGeneratedFilePath && @@ -54,7 +54,7 @@ request.ProjectKeyId is not null && // but the server clearly knows about it in a real project. That means its probably new, as Visual Studio opens a buffer // for a document before we get the notifications about it being added to any projects. Lets try refreshing before // we worry. - _outputWindowLogger?.LogDebug("Refreshing virtual documents, and waiting for them, (for {hostDocumentUri})", hostDocumentUri); + _logger?.LogDebug("Refreshing virtual documents, and waiting for them, (for {hostDocumentUri})", hostDocumentUri); var task = _csharpVirtualDocumentAddListener.WaitForDocumentAddAsync(cancellationToken); _documentManager.RefreshVirtualDocuments(); @@ -70,7 +70,7 @@ request.ProjectKeyId is not null && // sync with their understanding of the document contents, and since changes come in as a list of changes, // the user experience is broken. All we can do is hope the user closes and re-opens the document. Debug.Fail($"Server wants to update {hostDocumentUri} in {request.ProjectKeyId} but we don't know about the document being in any projects"); - _outputWindowLogger?.LogError("Server wants to update {hostDocumentUri} in {projectKeyId} by we only know about that document in misc files. Server and client are now out of sync.", hostDocumentUri, request.ProjectKeyId); + _logger?.LogError("Server wants to update {hostDocumentUri} in {projectKeyId} by we only know about that document in misc files. Server and client are now out of sync.", hostDocumentUri, request.ProjectKeyId); return; } } @@ -79,7 +79,7 @@ request.ProjectKeyId is not null && { if (virtualDocument.ProjectKey.Equals(ProjectKey.FromString(request.ProjectKeyId))) { - _outputWindowLogger?.LogDebug("UpdateCSharpBuffer virtual doc for {version} of {uri}", request.HostDocumentVersion.Value, virtualDocument.Uri); + _logger?.LogDebug("UpdateCSharpBuffer virtual doc for {version} of {uri}", request.HostDocumentVersion.Value, virtualDocument.Uri); _documentManager.UpdateVirtualDocument( hostDocumentUri, @@ -99,14 +99,14 @@ request.ProjectKeyId is not null && Debug.Fail("Multiple virtual documents seem to be supported, but none were updated, which is not impossible, but surprising."); } - _outputWindowLogger?.LogDebug("UpdateCSharpBuffer couldn't find any virtual docs for {version} of {uri}", request.HostDocumentVersion.Value, hostDocumentUri); + _logger?.LogDebug("UpdateCSharpBuffer couldn't find any virtual docs for {version} of {uri}", request.HostDocumentVersion.Value, hostDocumentUri); // Don't know about document, no-op. This can happen if the language server found a project.razor.json from an old build // and is sending us updates. return; } - _outputWindowLogger?.LogDebug("UpdateCSharpBuffer fallback for {version} of {uri}", request.HostDocumentVersion.Value, hostDocumentUri); + _logger?.LogDebug("UpdateCSharpBuffer fallback for {version} of {uri}", request.HostDocumentVersion.Value, hostDocumentUri); _documentManager.UpdateVirtualDocument( hostDocumentUri, diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs index 6931c7aef2c..178fa359572 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs @@ -13,7 +13,6 @@ using Microsoft.CodeAnalysis.Razor.Workspaces; using Microsoft.Extensions.Logging; using Microsoft.VisualStudio.Editor.Razor; -using Microsoft.VisualStudio.Editor.Razor.Logging; using Microsoft.VisualStudio.LanguageServer.ContainedLanguage; using Microsoft.VisualStudio.LanguageServer.Protocol; using Microsoft.VisualStudio.Text; @@ -35,7 +34,7 @@ internal partial class RazorCustomMessageTarget private readonly IClientSettingsManager _editorSettingsManager; private readonly LSPDocumentSynchronizer _documentSynchronizer; private readonly CSharpVirtualDocumentAddListener _csharpVirtualDocumentAddListener; - private readonly IOutputWindowLogger? _outputWindowLogger; + private ILogger? _logger; [ImportingConstructor] public RazorCustomMessageTarget( @@ -48,8 +47,7 @@ public RazorCustomMessageTarget( CSharpVirtualDocumentAddListener csharpVirtualDocumentAddListener, ITelemetryReporter telemetryReporter, LanguageServerFeatureOptions languageServerFeatureOptions, - ProjectSnapshotManagerAccessor projectSnapshotManagerAccessor, - [Import(AllowDefault = true)] IOutputWindowLogger? outputWindowLogger) + ProjectSnapshotManagerAccessor projectSnapshotManagerAccessor) { if (documentManager is null) { @@ -118,7 +116,11 @@ public RazorCustomMessageTarget( _telemetryReporter = telemetryReporter; _languageServerFeatureOptions = languageServerFeatureOptions; _projectSnapshotManagerAccessor = projectSnapshotManagerAccessor; - _outputWindowLogger = outputWindowLogger; + } + + internal void SetLogger(ILogger? logger) + { + _logger = logger; } private async Task GetProjectedRequestDetailsAsync(IDelegatedParams request, CancellationToken cancellationToken) @@ -180,21 +182,21 @@ private async Task> TrySynchronizeV if (virtualDocument is { ProjectKey.Id: null }) { - _outputWindowLogger?.LogDebug("Trying to sync to a doc with no project Id. Waiting for document add."); + _logger?.LogDebug("Trying to sync to a doc with no project Id. Waiting for document add."); if (await _csharpVirtualDocumentAddListener.WaitForDocumentAddAsync(cancellationToken).ConfigureAwait(false)) { - _outputWindowLogger?.LogDebug("Wait successful!"); + _logger?.LogDebug("Wait successful!"); virtualDocument = FindVirtualDocument(hostDocument.Uri, hostDocument.GetProjectContext()); } else { - _outputWindowLogger?.LogDebug("Timed out :("); + _logger?.LogDebug("Timed out :("); } } if (virtualDocument is null) { - _outputWindowLogger?.LogDebug("No virtual document found, falling back to old code."); + _logger?.LogDebug("No virtual document found, falling back to old code."); return await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync(requiredHostDocumentVersion, hostDocument.Uri, cancellationToken).ConfigureAwait(false); } @@ -203,16 +205,16 @@ private async Task> TrySynchronizeV // If we failed to sync on version 1, then it could be that we got new information while waiting, so try again if (requiredHostDocumentVersion == 1 && !result.Synchronized) { - _outputWindowLogger?.LogDebug("Sync failed for v1 document. Trying to get virtual document again."); + _logger?.LogDebug("Sync failed for v1 document. Trying to get virtual document again."); virtualDocument = FindVirtualDocument(hostDocument.Uri, hostDocument.GetProjectContext()); if (virtualDocument is null) { - _outputWindowLogger?.LogDebug("No virtual document found, falling back to old code."); + _logger?.LogDebug("No virtual document found, falling back to old code."); return await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync(requiredHostDocumentVersion, hostDocument.Uri, cancellationToken).ConfigureAwait(false); } - _outputWindowLogger?.LogDebug("Got virtual document after trying again {uri}. Trying to synchronize again.", virtualDocument.Uri); + _logger?.LogDebug("Got virtual document after trying again {uri}. Trying to synchronize again.", virtualDocument.Uri); // try again result = await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync(requiredHostDocumentVersion, hostDocument.Uri, virtualDocument.Uri, rejectOnNewerParallelRequest, cancellationToken).ConfigureAwait(false); diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs index 2df83bba33a..6a6bc275ed0 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorLanguageServerClient.cs @@ -192,6 +192,15 @@ public RazorLanguageServerClient( var loggers = _outputWindowLogger == null ? new ILogger[] { logHubLogger } : new ILogger[] { logHubLogger, _outputWindowLogger }; var razorLogger = new LoggerAdapter(loggers, _telemetryReporter, traceSource); var lspOptions = RazorLSPOptions.From(_clientSettingsManager.GetClientSettings()); + + // We want the LogHub logs to include logs from custom messages, but they are scoped to the lifetime of the + // server. The lifetime of the custom message logger is defined by MEF, and StreamJsonRpc has some static + // caching around messages it can handle etc. so we have to inject our logging separately. + var customMessageLogger = _loggerProvider.CreateLogger("CustomMessage"); + var customMessageLoggers = _outputWindowLogger == null ? new ILogger[] { customMessageLogger } : new ILogger[] { customMessageLogger, _outputWindowLogger }; + var logAdapter = new LoggerAdapter(customMessageLoggers, telemetryReporter: null, traceSource); + _customMessageTarget.SetLogger(logAdapter); + _server = RazorLanguageServerWrapper.Create( serverStream, serverStream, @@ -304,6 +313,8 @@ private async Task EnsureCleanedUpServerAsync() return; } + _customMessageTarget.SetLogger(logger: null); + if (_server is not null) { _projectConfigurationFilePathStore.Changed -= ProjectConfigurationFilePathStore_Changed; diff --git a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs index 06639cbd4fb..2da8cc9c769 100644 --- a/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs +++ b/src/Razor/test/Microsoft.VisualStudio.LanguageServerClient.Razor.Test/RazorCustomMessageTargetTest.cs @@ -69,8 +69,7 @@ public async Task UpdateCSharpBuffer_CannotLookupDocument_NoopsGracefully() new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), TestLanguageServerFeatureOptions.Instance, - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new UpdateBufferRequest() { HostDocumentFilePath = "C:/path/to/file.razor", @@ -110,8 +109,7 @@ public async Task UpdateCSharpBuffer_UpdatesDocument() new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), TestLanguageServerFeatureOptions.Instance, - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new UpdateBufferRequest() { HostDocumentFilePath = "C:/path/to/file.razor", @@ -162,8 +160,7 @@ public async Task UpdateCSharpBuffer_UpdatesCorrectDocument() new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), new TestLanguageServerFeatureOptions(includeProjectKeyInGeneratedFilePath: true), - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new UpdateBufferRequest() { ProjectKeyId = projectKey2.Id, @@ -201,8 +198,7 @@ public async Task ProvideCodeActionsAsync_CannotLookupDocument_ReturnsNullAsync( new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), TestLanguageServerFeatureOptions.Instance, - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new DelegatedCodeActionParams() { HostDocumentVersion = 1, @@ -272,7 +268,7 @@ async IAsyncEnumerable> var target = new RazorCustomMessageTarget( documentManager.Object, JoinableTaskContext, requestInvoker.Object, - TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict), outputWindowLogger); + TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict)); var request = new DelegatedCodeActionParams() { @@ -349,7 +345,7 @@ async IAsyncEnumerable> GetExpectedRe var target = new RazorCustomMessageTarget( documentManager, JoinableTaskContext, requestInvoker.Object, - TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer.Object, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict), outputWindowLogger); + TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer.Object, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict)); var codeAction = new VSInternalCodeAction() { @@ -386,8 +382,7 @@ public async Task ProvideSemanticTokensAsync_CannotLookupDocument_ReturnsNullAsy new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), TestLanguageServerFeatureOptions.Instance, - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new ProvideSemanticTokensRangeParams( textDocument: new TextDocumentIdentifier() { @@ -428,8 +423,7 @@ public async Task ProvideSemanticTokensAsync_CannotLookupVirtualDocument_Returns new CSharpVirtualDocumentAddListener(outputWindowLogger), Mock.Of(MockBehavior.Strict), TestLanguageServerFeatureOptions.Instance, - Mock.Of(MockBehavior.Strict), - outputWindowLogger); + Mock.Of(MockBehavior.Strict)); var request = new ProvideSemanticTokensRangeParams( textDocument: new TextDocumentIdentifier() { @@ -490,7 +484,7 @@ public async Task ProvideSemanticTokensAsync_ReturnsSemanticTokensAsync() var target = new RazorCustomMessageTarget( documentManager.Object, JoinableTaskContext, requestInvoker.Object, - TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer.Object, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict), outputWindowLogger); + TestFormattingOptionsProvider.Default, _editorSettingsManager, documentSynchronizer.Object, csharpVirtualDocumentAddListener, telemetryReporter.Object, TestLanguageServerFeatureOptions.Instance, Mock.Of(MockBehavior.Strict)); var request = new ProvideSemanticTokensRangeParams( textDocument: new TextDocumentIdentifier() { From d978327bba9465d338dcf5b153a2470a39ef8bd9 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:17:50 +1000 Subject: [PATCH 11/13] Log why we're trying to synchronize We get lots of these at the same time --- .../RazorCustomMessageTarget.cs | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs index 178fa359572..f710c49fc7e 100644 --- a/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs +++ b/src/Razor/src/Microsoft.VisualStudio.LanguageServerClient.Razor/RazorCustomMessageTarget.cs @@ -4,6 +4,7 @@ using System; using System.Composition; using System.Diagnostics; +using System.Runtime.CompilerServices; using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.Razor.LanguageServer.Extensions; @@ -167,7 +168,8 @@ private async Task> TrySynchronizeV int requiredHostDocumentVersion, TextDocumentIdentifier hostDocument, CancellationToken cancellationToken, - bool rejectOnNewerParallelRequest = true) + bool rejectOnNewerParallelRequest = true, + [CallerMemberName]string? caller = null) where TVirtualDocumentSnapshot : VirtualDocumentSnapshot { // For Html documents we don't do anything fancy, just call the standard service @@ -178,6 +180,8 @@ private async Task> TrySynchronizeV return await _documentSynchronizer.TrySynchronizeVirtualDocumentAsync(requiredHostDocumentVersion, hostDocument.Uri, cancellationToken).ConfigureAwait(false); } + _logger?.LogDebug("Trying to synchronize for {caller} to version {version} of {doc} for {project}", caller, requiredHostDocumentVersion, hostDocument.Uri, hostDocument.GetProjectContext()?.Id ?? "(no project context)"); + var virtualDocument = FindVirtualDocument(hostDocument.Uri, hostDocument.GetProjectContext()); if (virtualDocument is { ProjectKey.Id: null }) From 771305e67daea6e9bab3ccce1928386ec93fea18 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:29:56 +1000 Subject: [PATCH 12/13] Skip flaky test --- .../ProjectTests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs index a035945fbad..53aad71db28 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/ProjectTests.cs @@ -20,7 +20,7 @@ public async Task CreateFromTemplateAsync() await TestServices.SolutionExplorer.CloseSolutionAsync(ControlledHangMitigatingCancellationToken); } - [IdeFact] + [IdeFact(Skip = "https://github.com/dotnet/razor/issues/9200")] public async Task ChangeTargetFramework() { var solutionPath = await TestServices.SolutionExplorer.GetDirectoryNameAsync(ControlledHangMitigatingCancellationToken); From e0a02a0bd08dd6d91134d12448184c509951b985 Mon Sep 17 00:00:00 2001 From: David Wengier Date: Thu, 31 Aug 2023 11:31:17 +1000 Subject: [PATCH 13/13] Try to mitigate code folding test failures Code folding is one of the earliest LSP requests we get, and unlike semantic tokens we don't have an opportunity to tell the client we are ready to answer them. Hopefully a wait and a text change will improve the tests. --- .../CodeFoldingTests.cs | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/CodeFoldingTests.cs b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/CodeFoldingTests.cs index 5d98fd414b5..cd8258d26a3 100644 --- a/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/CodeFoldingTests.cs +++ b/src/Razor/test/Microsoft.VisualStudio.Razor.IntegrationTests/CodeFoldingTests.cs @@ -123,7 +123,7 @@ static CollapsibleBlock ConvertToLineNumbers(Span span, ITextView textView) } } - [IdeFact(Skip = "Flaky after multitarget work")] + [IdeFact] public async Task CodeFolding_CodeBlock() { await TestServices.SolutionExplorer.AddFileAsync( @@ -147,6 +147,10 @@ private void IncrementCount() open: true, ControlledHangMitigatingCancellationToken); + await TestServices.Editor.WaitForComponentClassificationAsync(ControlledHangMitigatingCancellationToken); + + TestServices.Input.Send("{ENTER}"); + await AssertFoldableBlocksAsync( @"@code { private int currentCount = 0; @@ -190,6 +194,10 @@ await TestServices.SolutionExplorer.AddFileAsync( open: true, ControlledHangMitigatingCancellationToken); + await TestServices.Editor.WaitForComponentClassificationAsync(ControlledHangMitigatingCancellationToken); + + TestServices.Input.Send("{ENTER}"); + await AssertFoldableBlocksAsync( @"@if(true) { @@ -232,6 +240,10 @@ await TestServices.SolutionExplorer.AddFileAsync( open: true, ControlledHangMitigatingCancellationToken); + await TestServices.Editor.WaitForComponentClassificationAsync(ControlledHangMitigatingCancellationToken); + + TestServices.Input.Send("{ENTER}"); + await AssertFoldableBlocksAsync( @"@foreach (var s in GetStuff()) { @@ -265,6 +277,10 @@ void M2() { } open: true, ControlledHangMitigatingCancellationToken); + await TestServices.Editor.WaitForComponentClassificationAsync(ControlledHangMitigatingCancellationToken); + + TestServices.Input.Send("{ENTER}"); + await AssertFoldableBlocksAsync( @"#region Methods void M1() { }