Tag Helper Discovery Telemetry (#9602)

As discussed at various times, here is some telemetry to _maybe_ help us
track down tag helper issues.

I'm no telemetry expert here, but my hope is with these queries we'll be
able to find things like:

* Occurances of tag helper discovery never finishing (i've seen this on
my machine, but maybe nowhere else?)
* Where tag helper discovery results in us losing tag helper information
* Sessions that never get a non-zero number of tag helpers
* How often we're trying to discover tag helpers in general
(with/without any changes)

Please keep that in mind when reviewing. I don't know how to write the
Kusto queries for those, I'm just assuming that I, or someone smarter
than I, will be able to work it out later :)

Also removing some old telemetry which I don't think we've ever used,
and looking at the data, I'm not sure what problem we thought we had
that we were looking for, but we don't seem to have it. Either the
response is instant, or the data is bad. Neither is useful.
<img width="127" alt="image"
src="https://github.com/dotnet/razor/assets/754264/c99d78e1-b2ca-4474-a33e-9807288e9910">

Author: davidwengier

src/Razor/src/Microsoft.CodeAnalysis.Razor.Workspaces/DefaultProjectWorkspaceStateGenerator.cs

@@ -9,7 +9,9 @@
 using System.Diagnostics;
 using System.Threading;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Razor.PooledObjects;
 using Microsoft.AspNetCore.Razor.ProjectSystem;
+using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.CodeAnalysis.CSharp;
 using Microsoft.CodeAnalysis.Razor.ProjectSystem;
 using Microsoft.CodeAnalysis.Razor.Workspaces;
@@ -19,31 +21,20 @@ namespace Microsoft.CodeAnalysis.Razor;
 [Shared]
 [Export(typeof(ProjectWorkspaceStateGenerator))]
 [Export(typeof(IProjectSnapshotChangeTrigger))]
-internal class DefaultProjectWorkspaceStateGenerator : ProjectWorkspaceStateGenerator, IDisposable
+[method: ImportingConstructor]
+internal class DefaultProjectWorkspaceStateGenerator(ProjectSnapshotManagerDispatcher projectSnapshotManagerDispatcher, ITelemetryReporter telemetryReporter) : ProjectWorkspaceStateGenerator, IDisposable
 {
     // Internal for testing
-    internal readonly Dictionary<ProjectKey, UpdateItem> Updates;
+    internal readonly Dictionary<ProjectKey, UpdateItem> Updates = new();
+
+    private readonly ProjectSnapshotManagerDispatcher _projectSnapshotManagerDispatcher = projectSnapshotManagerDispatcher ?? throw new ArgumentNullException(nameof(projectSnapshotManagerDispatcher));
+    private readonly ITelemetryReporter _telemetryReporter = telemetryReporter ?? throw new ArgumentNullException(nameof(telemetryReporter));
+    private readonly SemaphoreSlim _semaphore = new SemaphoreSlim(initialCount: 1);
 
-    private readonly ProjectSnapshotManagerDispatcher _projectSnapshotManagerDispatcher;
-    private readonly SemaphoreSlim _semaphore;
     private ProjectSnapshotManagerBase _projectManager;
     private ITagHelperResolver _tagHelperResolver;
     private bool _disposed;
 
-    [ImportingConstructor]
-    public DefaultProjectWorkspaceStateGenerator(ProjectSnapshotManagerDispatcher projectSnapshotManagerDispatcher)
-    {
-        if (projectSnapshotManagerDispatcher is null)
-        {
-            throw new ArgumentNullException(nameof(projectSnapshotManagerDispatcher));
-        }
-
-        _projectSnapshotManagerDispatcher = projectSnapshotManagerDispatcher;
-
-        _semaphore = new SemaphoreSlim(initialCount: 1);
-        Updates = new Dictionary<ProjectKey, UpdateItem>();
-    }
-
     // Used in unit tests to ensure we can control when background work starts.
     public ManualResetEventSlim BlockBackgroundWorkStart { get; set; }
 
@@ -134,6 +125,12 @@ private async Task UpdateWorkspaceStateAsync(Project workspaceProject, IProjectS
             return;
         }
 
+        // Specifically not using BeginBlock because we want to capture cases where tag helper discovery never finishes.
+        var telemetryId = Guid.NewGuid();
+        _telemetryReporter.ReportEvent("taghelperresolve/begin", Severity.Normal,
+            new Property("id", telemetryId),
+            new Property("tagHelperCount", projectSnapshot.ProjectWorkspaceState?.TagHelpers.Length ?? 0));
+
         try
         {
             // Only allow a single TagHelper resolver request to process at a time in order to reduce Visual Studio memory pressure. Typically a TagHelper resolution result can be upwards of 10mb+.
@@ -173,17 +170,35 @@ private async Task UpdateWorkspaceStateAsync(Project workspaceProject, IProjectS
                         csharpLanguageVersion = csharpParseOptions.LanguageVersion;
                     }
 
+                    using var _ = StopwatchPool.GetPooledObject(out var watch);
+
+                    watch.Restart();
                     var tagHelpers = await _tagHelperResolver.GetTagHelpersAsync(workspaceProject, projectSnapshot, cancellationToken).ConfigureAwait(false);
+                    watch.Stop();
+
+                    _telemetryReporter.ReportEvent("taghelperresolve/end", Severity.Normal,
+                        new Property("id", telemetryId),
+                        new Property("ellapsedms", watch.ElapsedMilliseconds),
+                        new Property("result", "success"),
+                        new Property("tagHelperCount", tagHelpers.Length));
+
                     workspaceState = new ProjectWorkspaceState(tagHelpers, csharpLanguageVersion);
                 }
             }
             catch (OperationCanceledException)
             {
                 // Abort work if we get a task cancelled exception
+                _telemetryReporter.ReportEvent("taghelperresolve/end", Severity.Normal,
+                    new Property("id", telemetryId),
+                    new Property("result", "cancel"));
                 return;
             }
             catch (Exception ex)
             {
+                _telemetryReporter.ReportEvent("taghelperresolve/end", Severity.Normal,
+                    new Property("id", telemetryId),
+                    new Property("result", "error"));
+
                 await _projectSnapshotManagerDispatcher.RunOnDispatcherThreadAsync(
                    () => _projectManager.ReportError(ex, projectSnapshot),
                    // Don't allow errors to be cancelled

src/Razor/src/Microsoft.CodeAnalysis.Remote.Razor/OOPTagHelperResolver.cs

@@ -25,14 +25,12 @@ internal class OOPTagHelperResolver : ITagHelperResolver
     private readonly ProjectSnapshotProjectEngineFactory _factory;
     private readonly IErrorReporter _errorReporter;
     private readonly Workspace _workspace;
-    private readonly ITelemetryReporter _telemetryReporter;
 
     public OOPTagHelperResolver(ProjectSnapshotProjectEngineFactory factory, IErrorReporter errorReporter, Workspace workspace, ITelemetryReporter telemetryReporter)
     {
         _factory = factory ?? throw new ArgumentNullException(nameof(factory));
         _errorReporter = errorReporter ?? throw new ArgumentNullException(nameof(errorReporter));
         _workspace = workspace ?? throw new ArgumentNullException(nameof(workspace));
-        _telemetryReporter = telemetryReporter ?? throw new ArgumentNullException(nameof(telemetryReporter));
 
         _innerResolver = new CompilationTagHelperResolver(telemetryReporter);
         _resultCache = new TagHelperResultCache();
@@ -186,16 +184,10 @@ protected virtual async ValueTask<ImmutableArray<TagHelperDescriptor>> ResolveTa
     // Protected virtual for testing
     protected virtual ImmutableArray<Checksum> ProduceChecksumsFromDelta(ProjectId projectId, int lastResultId, TagHelperDeltaResult deltaResult)
     {
-        using var _ = StopwatchPool.GetPooledObject(out var stopWatch);
-        stopWatch.Restart();
-
-        var fromCache = true;
-
         if (!_resultCache.TryGet(projectId, lastResultId, out var checksums))
         {
             // We most likely haven't made a request to the server yet so there's no delta to apply
             checksums = ImmutableArray<Checksum>.Empty;
-            fromCache = false;
 
             if (deltaResult.IsDelta)
             {
@@ -208,24 +200,13 @@ protected virtual ImmutableArray<Checksum> ProduceChecksumsFromDelta(ProjectId p
         {
             // Not a delta based response, we should treat it as a "refresh"
             checksums = ImmutableArray<Checksum>.Empty;
-            fromCache = false;
         }
 
         if (deltaResult.ResultId != lastResultId)
         {
             // New results, lets build a coherent TagHelper collection and then cache it
             checksums = deltaResult.Apply(checksums);
             _resultCache.Set(projectId, deltaResult.ResultId, checksums);
-            fromCache = false;
-        }
-
-        stopWatch.Stop();
-        if (fromCache)
-        {
-            _telemetryReporter.ReportEvent(
-                "taghelpers.fromcache",
-                Severity.Normal,
-                new Property("taghelper.cachedresult.ellapsedms", stopWatch.ElapsedMilliseconds));
         }
 
         return checksums;

src/Razor/test/Microsoft.VisualStudio.Editor.Razor.Test/DefaultProjectWorkspaceStateGeneratorTest.cs

@@ -11,6 +11,7 @@
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Razor.Language;
 using Microsoft.AspNetCore.Razor.ProjectSystem;
+using Microsoft.AspNetCore.Razor.Telemetry;
 using Microsoft.CodeAnalysis.Host;
 using Microsoft.CodeAnalysis.Razor.ProjectSystem;
 using Xunit;
@@ -58,7 +59,7 @@ public DefaultProjectWorkspaceStateGeneratorTest(ITestOutputHelper testOutput)
     public void Dispose_MakesUpdateNoop()
     {
         // Arrange
-        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher))
+        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher, NoOpTelemetryReporter.Instance))
         {
             stateGenerator.BlockBackgroundWorkStart = new ManualResetEventSlim(initialState: false);
 
@@ -75,7 +76,7 @@ public void Dispose_MakesUpdateNoop()
     public void Update_StartsUpdateTask()
     {
         // Arrange
-        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher))
+        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher, NoOpTelemetryReporter.Instance))
         {
             stateGenerator.BlockBackgroundWorkStart = new ManualResetEventSlim(initialState: false);
 
@@ -92,7 +93,7 @@ public void Update_StartsUpdateTask()
     public void Update_SoftCancelsIncompleteTaskForSameProject()
     {
         // Arrange
-        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher))
+        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher, NoOpTelemetryReporter.Instance))
         {
             stateGenerator.BlockBackgroundWorkStart = new ManualResetEventSlim(initialState: false);
             stateGenerator.Update(_workspaceProject, _projectSnapshot, DisposalToken);
@@ -110,7 +111,7 @@ public void Update_SoftCancelsIncompleteTaskForSameProject()
     public async Task Update_NullWorkspaceProject_ClearsProjectWorkspaceState()
     {
         // Arrange
-        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher))
+        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher, NoOpTelemetryReporter.Instance))
         {
             stateGenerator.NotifyBackgroundWorkCompleted = new ManualResetEventSlim(initialState: false);
             var projectManager = new TestProjectSnapshotManager(_workspace, Dispatcher);
@@ -134,7 +135,7 @@ public async Task Update_NullWorkspaceProject_ClearsProjectWorkspaceState()
     public async Task Update_ResolvesTagHelpersAndUpdatesWorkspaceState()
     {
         // Arrange
-        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher))
+        using (var stateGenerator = new DefaultProjectWorkspaceStateGenerator(Dispatcher, NoOpTelemetryReporter.Instance))
         {
             stateGenerator.NotifyBackgroundWorkCompleted = new ManualResetEventSlim(initialState: false);
             var projectManager = new TestProjectSnapshotManager(_workspace, Dispatcher);