Add counter telemetry log aggregator and cleanup implemention to ensure

it always gets posted
dotnet · Oct 10, 2024 · 47eac67 · 47eac67
1 parent cbcfb4a
commit 47eac67
Show file tree

Hide file tree

Showing 25 changed files with 318 additions and 320 deletions.
diff --git a/src/EditorFeatures/Core.Wpf/Suggestions/SuggestedActions/SuggestedAction.cs b/src/EditorFeatures/Core.Wpf/Suggestions/SuggestedActions/SuggestedAction.cs
@@ -116,7 +116,7 @@ private async Task InvokeAsync()
         {
             try
             {
-                using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.SuggestedAction_Application_Summary, $"Total");
+                using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Application_Summary, $"Total");
 
                 using var token = SourceProvider.OperationListener.BeginAsyncOperation($"{nameof(SuggestedAction)}.{nameof(Invoke)}");
                 using var context = SourceProvider.UIThreadOperationExecutor.BeginExecute(

diff --git a/src/EditorFeatures/Core.Wpf/Suggestions/SuggestedActionsSource_Async.cs b/src/EditorFeatures/Core.Wpf/Suggestions/SuggestedActionsSource_Async.cs
@@ -113,14 +113,14 @@ private async Task GetSuggestedActionsWorkerAsync(
                         // then pass it continuously from one priority group to the next.
                         var lowPriorityAnalyzerData = new SuggestedActionPriorityProvider.LowPriorityAnalyzersAndDiagnosticIds();
 
-                        using var _2 = TelemetryLogging.LogBlockTimeAggregated(FunctionId.SuggestedAction_Summary, $"Total");
+                        using var _2 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total");
 
                         // Collectors are in priority order.  So just walk them from highest to lowest.
                         foreach (var collector in collectors)
                         {
                             if (TryGetPriority(collector.Priority) is CodeActionRequestPriority priority)
                             {
-                                using var _3 = TelemetryLogging.LogBlockTimeAggregated(FunctionId.SuggestedAction_Summary, $"Total.Pri{(int)priority}");
+                                using var _3 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{(int)priority}");
 
                                 var allSets = GetCodeFixesAndRefactoringsAsync(
                                     state, requestedActionCategories, document,
@@ -229,7 +229,7 @@ private async IAsyncEnumerable<SuggestedActionSet> GetCodeFixesAndRefactoringsAs
 
                 async Task<ImmutableArray<UnifiedSuggestedActionSet>> GetCodeFixesAsync()
                 {
-                    using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.SuggestedAction_Summary, $"Total.Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetCodeFixesAsync)}");
+                    using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetCodeFixesAsync)}");
 
                     if (owner._codeFixService == null ||
                         !supportsFeatureService.SupportsCodeFixes(target.SubjectBuffer) ||
@@ -245,7 +245,7 @@ async Task<ImmutableArray<UnifiedSuggestedActionSet>> GetCodeFixesAsync()
 
                 async Task<ImmutableArray<UnifiedSuggestedActionSet>> GetRefactoringsAsync()
                 {
-                    using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.SuggestedAction_Summary, $"Total.Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetRefactoringsAsync)}");
+                    using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetRefactoringsAsync)}");
 
                     if (!selection.HasValue)
                     {

diff --git a/src/Features/Core/Portable/CodeRefactorings/CodeRefactoringService.cs b/src/Features/Core/Portable/CodeRefactorings/CodeRefactoringService.cs
@@ -152,7 +152,7 @@ public async Task<ImmutableArray<CodeRefactoring>> GetRefactoringsAsync(
         CodeActionRequestPriority? priority,
         CancellationToken cancellationToken)
     {
-        using (TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeRefactoring_Summary, $"Pri{priority.GetPriorityInt()}"))
+        using (TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeRefactoring_Summary, $"Pri{priority.GetPriorityInt()}"))
         using (Logger.LogBlock(FunctionId.Refactoring_CodeRefactoringService_GetRefactoringsAsync, cancellationToken))
         {
             using var _ = PooledDictionary<CodeRefactoringProvider, int>.GetInstance(out var providerToIndex);

diff --git a/...ageServer/Microsoft.CodeAnalysis.LanguageServer/Telemetry/VSCodeRequestTelemetryLogger.cs b/...ageServer/Microsoft.CodeAnalysis.LanguageServer/Telemetry/VSCodeRequestTelemetryLogger.cs
@@ -21,14 +21,6 @@ internal class VSCodeRequestTelemetryLogger() : RequestTelemetryLogger(WellKnown
     /// </summary>
     private static bool s_initialProjectLoadCompleted = false;
 
-    /// <summary>
-    /// Store which workspace a document came from for each request.  This is tracked separately before and after initial project load:
-    ///   1.  Before initial load, almost all requests should resolve to the misc files workspace.
-    ///   2.  After initial load, almost all requests should resolve to the host workspace.
-    /// A large amount of misc files requests in 2 could indicate either a bug or feature improvements in order to load what the user is expecting.
-    /// </summary>
-    private readonly ConcurrentDictionary<bool, CountLogAggregator<string>> _findDocumentCounters = new();
-
     public static void ReportProjectInitializationComplete()
     {
         s_initialProjectLoadCompleted = true;
@@ -40,30 +32,17 @@ public static void ReportProjectLoadStarted()
         Logger.Log(FunctionId.VSCode_Project_Load_Started, logLevel: LogLevel.Information);
     }
 
-    protected override void IncreaseFindDocumentCount(string workspaceInfo)
+    protected override void IncreaseFindDocumentCount(string workspaceCountMetricName)
     {
-        _findDocumentCounters.GetOrAdd(s_initialProjectLoadCompleted, (_) => new CountLogAggregator<string>()).IncreaseCount(workspaceInfo);
-    }
-
-    protected override void ReportFindDocumentCounter()
-    {
-        foreach (var (isInitialLoadComplete, counter) in _findDocumentCounters)
+        TelemetryLogging.LogAggregatedCounter(FunctionId.LSP_FindDocumentInWorkspace, KeyValueLogMessage.Create(m =>
         {
-            if (!counter.IsEmpty)
-            {
-                TelemetryLogging.Log(FunctionId.LSP_FindDocumentInWorkspace, KeyValueLogMessage.Create(LogType.Trace, m =>
-                {
-                    m["server"] = ServerTypeName;
-                    m["projectsLoaded"] = isInitialLoadComplete;
-                    foreach (var kvp in counter)
-                    {
-                        var info = kvp.Key.ToString()!;
-                        m[info] = kvp.Value.GetCount();
-                    }
-                }));
-            }
-        }
-        _findDocumentCounters.Clear();
+            var projectsLoaded = s_initialProjectLoadCompleted;
+            m[TelemetryLogging.KeyName] = ServerTypeName + "." + workspaceCountMetricName + "." + projectsLoaded;
+            m[TelemetryLogging.KeyValue] = 1L;
+            m[TelemetryLogging.KeyMetricName] = workspaceCountMetricName;
+            m["server"] = ServerTypeName;
+            m["workspace"] = workspaceCountMetricName;
+            m["projectsLoaded"] = projectsLoaded;
+        }));
     }
-
 }
diff --git a/src/LanguageServer/Protocol/Features/CodeFixes/CodeFixService.cs b/src/LanguageServer/Protocol/Features/CodeFixes/CodeFixService.cs
@@ -101,11 +101,11 @@ public CodeFixService(
         public async Task<CodeFixCollection?> GetMostSevereFixAsync(
             TextDocument document, TextSpan range, ICodeActionRequestPriorityProvider priorityProvider, CancellationToken cancellationToken)
         {
-            using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}");
+            using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}");
 
             ImmutableArray<DiagnosticData> allDiagnostics;
 
-            using (TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
+            using (TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
             {
                 allDiagnostics = await _diagnosticService.GetDiagnosticsForSpanAsync(
                     document, range, GetShouldIncludeDiagnosticPredicate(document, priorityProvider),
@@ -172,7 +172,7 @@ public async IAsyncEnumerable<CodeFixCollection> StreamFixesAsync(
             ICodeActionRequestPriorityProvider priorityProvider,
             [EnumeratorCancellation] CancellationToken cancellationToken)
         {
-            using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}");
+            using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}");
 
             // We only need to compute suppression/configuration fixes when request priority is
             // 'CodeActionPriorityRequest.Lowest' or no priority was provided at all (so all providers should run).
@@ -190,7 +190,7 @@ public async IAsyncEnumerable<CodeFixCollection> StreamFixesAsync(
             // user-invoked diagnostic requests, for example, user invoked Ctrl + Dot operation for lightbulb.
             ImmutableArray<DiagnosticData> diagnostics;
 
-            using (TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
+            using (TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priorityProvider.Priority.GetPriorityInt()}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
             {
                 diagnostics = await _diagnosticService.GetDiagnosticsForSpanAsync(
                     document, range, GetShouldIncludeDiagnosticPredicate(document, priorityProvider),
@@ -286,10 +286,10 @@ private static SortedDictionary<TextSpan, List<DiagnosticData>> ConvertToMap(
         {
             cancellationToken.ThrowIfCancellationRequested();
 
-            using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}");
+            using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}");
             ImmutableArray<DiagnosticData> diagnostics;
 
-            using (TelemetryLogging.LogBlockTimeAggregated(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
+            using (TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}.{nameof(_diagnosticService.GetDiagnosticsForSpanAsync)}"))
             {
                 diagnostics = await _diagnosticService.GetDiagnosticsForSpanAsync(
                     document, range, diagnosticId, includeSuppressedDiagnostics: false, priorityProvider: new DefaultCodeActionRequestPriorityProvider(),

diff --git a/src/LanguageServer/Protocol/Features/Diagnostics/DocumentAnalysisExecutor.cs b/src/LanguageServer/Protocol/Features/Diagnostics/DocumentAnalysisExecutor.cs
@@ -240,7 +240,7 @@ private async Task<ImmutableArray<DiagnosticData>> GetSyntaxDiagnosticsAsync(Dia
 
             if (_lazySyntaxDiagnostics == null)
             {
-                using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSyntaxDiagnosticsAsync)}.{nameof(GetAnalysisResultAsync)}");
+                using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSyntaxDiagnosticsAsync)}.{nameof(GetAnalysisResultAsync)}");
 
                 var analysisScope = AnalysisScope.WithAnalyzers(_compilationBasedAnalyzersInAnalysisScope);
                 var syntaxDiagnostics = await GetAnalysisResultAsync(analysisScope, cancellationToken).ConfigureAwait(false);
@@ -276,7 +276,7 @@ private async Task<ImmutableArray<DiagnosticData>> GetSemanticDiagnosticsAsync(D
 
             if (_lazySemanticDiagnostics == null)
             {
-                using var _ = TelemetryLogging.LogBlockTimeAggregated(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSemanticDiagnosticsAsync)}.{nameof(GetAnalysisResultAsync)}");
+                using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSemanticDiagnosticsAsync)}.{nameof(GetAnalysisResultAsync)}");
 
                 var analysisScope = AnalysisScope.WithAnalyzers(_compilationBasedAnalyzersInAnalysisScope);
                 var semanticDiagnostics = await GetAnalysisResultAsync(analysisScope, cancellationToken).ConfigureAwait(false);

diff --git a/...ocol/Features/Diagnostics/EngineV2/DiagnosticIncrementalAnalyzer_GetDiagnosticsForSpan.cs b/...ocol/Features/Diagnostics/EngineV2/DiagnosticIncrementalAnalyzer_GetDiagnosticsForSpan.cs
@@ -196,7 +196,7 @@ public async Task GetAsync(ArrayBuilder<DiagnosticData> list, CancellationToken
                     using var _2 = ArrayBuilder<AnalyzerWithState>.GetInstance(out var semanticSpanBasedAnalyzers);
                     using var _3 = ArrayBuilder<AnalyzerWithState>.GetInstance(out var semanticDocumentBasedAnalyzers);
 
-                    using var _4 = TelemetryLogging.LogBlockTimeAggregated(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}");
+                    using var _4 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}");
 
                     foreach (var stateSet in _stateSets)
                     {
@@ -383,7 +383,7 @@ private async Task ComputeDocumentDiagnosticsAsync(
                 ImmutableDictionary<DiagnosticAnalyzer, ImmutableArray<DiagnosticData>> diagnosticsMap;
                 if (incrementalAnalysis)
                 {
-                    using var _2 = TelemetryLogging.LogBlockTimeAggregated(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}.Incremental");
+                    using var _2 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}.Incremental");
 
                     diagnosticsMap = await _owner._incrementalMemberEditAnalyzer.ComputeDiagnosticsAsync(
                         executor,
@@ -395,7 +395,7 @@ private async Task ComputeDocumentDiagnosticsAsync(
                 }
                 else
                 {
-                    using var _2 = TelemetryLogging.LogBlockTimeAggregated(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}.Document");
+                    using var _2 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"Pri{_priorityProvider.Priority.GetPriorityInt()}.Document");
 
                     diagnosticsMap = await ComputeDocumentDiagnosticsCoreAsync(executor, cancellationToken).ConfigureAwait(false);
                 }