Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
34 commits
Select commit Hold shift + click to select a range
e3b2647
Consolidate Roslyn telemetry onto one event sink and one metric sink
dibarbet Aug 26, 2026
6c3501a
Fix Razor VS Code metric data loss; delete the LSP host's ITelemetryR…
dibarbet Aug 26, 2026
bd9da50
Move the Razor telemetry bridge's translation into the bridge
dibarbet Aug 26, 2026
16585d5
Rewrite added comments to describe current behavior
dibarbet Aug 26, 2026
6381484
Revert documentation changes
dibarbet Aug 26, 2026
d91ab67
Fan out events from RoslynTelemetry; delete AggregateEventSink
dibarbet Aug 27, 2026
de78c12
Drop the unused ambient session plumbing; one metric sink per session
dibarbet Aug 27, 2026
1db5b85
Wire the language server's metric sink; separate host and dynamic eve…
dibarbet Aug 27, 2026
16e79fc
Reduce event sink registration to AddEventSink returning a registration
dibarbet Aug 27, 2026
c3767fe
Rename LanguageServerTelemetryService; give metric sinks the same reg…
dibarbet Aug 27, 2026
23513fc
Collapse each host's telemetry teardown to one disposables array
dibarbet Aug 27, 2026
bf1f140
Register the trace and output window sinks only while they are enabled
dibarbet Aug 27, 2026
34e618a
Keep the ETW sink dynamic in the OOP process
dibarbet Aug 27, 2026
62d18fd
Put the LanguageServerTelemetry attribute on its own line
dibarbet Aug 27, 2026
dd7bd60
Remove dead telemetry surface and tighten the new comments
dibarbet Aug 27, 2026
97cad27
Fix regressions found in review
dibarbet Aug 27, 2026
1f97462
Don't dispose the flush loop's cancellation source
dibarbet Aug 27, 2026
ddb29cf
Register the ETW sink on demand in devenv too
dibarbet Aug 27, 2026
9d50d06
Pin the metric naming and document two deliberate gaps
dibarbet Aug 27, 2026
c1fe39b
Drop forward-looking notes from the telemetry comments
dibarbet Aug 27, 2026
03f12e8
Flush the language server's request telemetry when a server shuts down
dibarbet Aug 27, 2026
4f9491a
Test OOP logger enablement without a telemetry session
dibarbet Aug 27, 2026
af1028f
Revert the block pairing bitmask
dibarbet Aug 27, 2026
e05ecb0
Apply PR feedback on comments
dibarbet Aug 27, 2026
0195260
Close the flush race, name the instrument kinds, share the naming
dibarbet Aug 27, 2026
4a0b8e2
Make the telemetry test accessors static
dibarbet Aug 27, 2026
6a11d59
Fix analyzer violations in projects with stricter settings
dibarbet Aug 28, 2026
9f43ea2
Enable nullable in the new language server telemetry tests
dibarbet Aug 28, 2026
50d3af4
only allow sink to be registered once
dibarbet Aug 31, 2026
0397ff8
sort
dibarbet Aug 31, 2026
1f2ddb5
Address telemetry consolidation review feedback
dibarbet Sep 2, 2026
0da1307
potential simplification for flush lock
dibarbet Sep 2, 2026
f203195
simplify tests
dibarbet Sep 2, 2026
aca50e9
Address metric sink review feedback
dibarbet Sep 3, 2026
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ private void PostTelemetry(bool isCommit)
if (_suggestionsPanelTelemetry is not null)
{
RoslynDebug.Assert(_suggestionsDropdownTelemetry is null);
TelemetryLogging.Log(FunctionId.Copilot_Rename, KeyValueLogMessage.Create(m =>
RoslynTelemetry.Log(FunctionId.Copilot_Rename, KeyValueLogMessage.Create(m =>
{
m[nameof(isCommit)] = isCommit;
m["UseSuggestionsPanel"] = true;
Expand All @@ -61,7 +61,7 @@ private void PostTelemetry(bool isCommit)
else
{
RoslynDebug.Assert(_suggestionsDropdownTelemetry is not null);
TelemetryLogging.Log(FunctionId.Copilot_Rename, KeyValueLogMessage.Create(m =>
RoslynTelemetry.Log(FunctionId.Copilot_Rename, KeyValueLogMessage.Create(m =>
{
m[nameof(isCommit)] = isCommit;
m["UseDropDown"] = true;
Expand Down
11 changes: 1 addition & 10 deletions src/EditorFeatures/Core/Remote/SolutionChecksumUpdater.cs
Original file line number Diff line number Diff line change
Expand Up @@ -43,8 +43,6 @@ internal sealed class SolutionChecksumUpdater : IDisposable

private const string SynchronizeTextChangesStatusSucceededMetricName = "SucceededCount";
private const string SynchronizeTextChangesStatusFailedMetricName = "FailedCount";
private const string SynchronizeTextChangesStatusSucceededKeyName = nameof(SolutionChecksumUpdater) + "." + SynchronizeTextChangesStatusSucceededMetricName;
private const string SynchronizeTextChangesStatusFailedKeyName = nameof(SolutionChecksumUpdater) + "." + SynchronizeTextChangesStatusFailedMetricName;

public SolutionChecksumUpdater(
Workspace workspace,
Expand Down Expand Up @@ -192,14 +190,7 @@ private async Task DispatchSynchronizeTextChangesAsync(

// Update aggregated telemetry with success status of sending the synchronization data.
var metricName = wasSynchronized.Value ? SynchronizeTextChangesStatusSucceededMetricName : SynchronizeTextChangesStatusFailedMetricName;
var keyName = wasSynchronized.Value ? SynchronizeTextChangesStatusSucceededKeyName : SynchronizeTextChangesStatusFailedKeyName;
TelemetryLogging.LogAggregatedCounter(FunctionId.ChecksumUpdater_SynchronizeTextChangesStatus, KeyValueLogMessage.Create(static (m, args) =>
{
var (keyName, metricName) = args;
m[TelemetryLogging.KeyName] = keyName;
m[TelemetryLogging.KeyValue] = 1L;
m[TelemetryLogging.KeyMetricName] = metricName;
}, (keyName, metricName)));
RoslynTelemetry.Count(FunctionId.ChecksumUpdater_SynchronizeTextChangesStatus, metricName, 1);

return;

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -101,7 +101,7 @@ private async Task InvokeAsync()
{
try
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Application_Summary, $"Total");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.SuggestedAction_Application_Summary, $"Total");

using var token = SourceProvider.OperationListener.BeginAsyncOperation($"{nameof(EditorSuggestedAction)}.{nameof(Invoke)}");
using var context = SourceProvider.UIThreadOperationExecutor.BeginExecute(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -104,14 +104,14 @@ await document.Project.Solution.Services.GetRequiredService<IWorkspaceStatusServ

try
{
using var _2 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total");
using var _2 = RoslynTelemetry.RecordBlockTime(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.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{(int)priority}");
using var _3 = RoslynTelemetry.RecordBlockTime(FunctionId.SuggestedAction_Summary, $"Total.Pri{(int)priority}");

var allSets = GetCodeFixesAndRefactoringsAsync(
state, requestedActionCategories, document,
Expand Down Expand Up @@ -219,7 +219,7 @@ await document.Project.Solution.Services.GetRequiredService<IWorkspaceStatusServ

async Task<ImmutableArray<CodeAnalysis.Suggestions.SuggestedActionSet>> GetCodeFixesAsync()
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{priority.GetPriorityInt()}.{nameof(GetCodeFixesAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.SuggestedAction_Summary, $"Total.Pri{priority.GetPriorityInt()}.{nameof(GetCodeFixesAsync)}");

if (owner._codeFixService == null ||
!supportsFeatureService.SupportsCodeFixes(target.SubjectBuffer) ||
Expand All @@ -235,7 +235,7 @@ await document.Project.Solution.Services.GetRequiredService<IWorkspaceStatusServ

async Task<ImmutableArray<CodeAnalysis.Suggestions.SuggestedActionSet>> GetRefactoringsAsync()
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.SuggestedAction_Summary, $"Total.Pri{priority.GetPriorityInt()}.{nameof(GetRefactoringsAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.SuggestedAction_Summary, $"Total.Pri{priority.GetPriorityInt()}.{nameof(GetRefactoringsAsync)}");

if (!selection.HasValue)
{
Expand Down
18 changes: 9 additions & 9 deletions src/Features/Core/Portable/CodeFixes/Service/CodeFixService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -95,11 +95,11 @@ private DiagnosticIdFilter GetShouldIncludeDiagnosticPredicate(
public async Task<CodeFixCollection?> GetMostSevereFixAsync(
TextDocument document, TextSpan range, CodeActionRequestPriority? priority, CancellationToken cancellationToken)
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.CodeFix_Summary, $"Pri{priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}");

ImmutableArray<DiagnosticData> allDiagnostics;

using (TelemetryLogging.LogBlockTimeAggregatedHistogram(
using (RoslynTelemetry.RecordBlockTime(
FunctionId.CodeFix_Summary, $"Pri{priority.GetPriorityInt()}.{nameof(GetMostSevereFixAsync)}.{nameof(IDiagnosticAnalyzerService.GetDiagnosticsForSpanAsync)}"))
{
var service = document.Project.Solution.Services.GetRequiredService<IDiagnosticAnalyzerService>();
Expand Down Expand Up @@ -173,7 +173,7 @@ public async IAsyncEnumerable<CodeFixCollection> StreamFixesAsync(
CodeActionRequestPriority? priority,
[EnumeratorCancellation] CancellationToken cancellationToken)
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"Pri{priority.GetPriorityInt()}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.CodeFix_Summary, $"Pri{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).
Expand All @@ -191,7 +191,7 @@ public async IAsyncEnumerable<CodeFixCollection> StreamFixesAsync(
// user-invoked diagnostic requests, for example, user invoked Ctrl + Dot operation for lightbulb.
ImmutableArray<DiagnosticData> diagnostics;

using (TelemetryLogging.LogBlockTimeAggregatedHistogram(
using (RoslynTelemetry.RecordBlockTime(
FunctionId.CodeFix_Summary, $"Pri{priority.GetPriorityInt()}.{nameof(IDiagnosticAnalyzerService.GetDiagnosticsForSpanAsync)}"))
{
var service = document.Project.Solution.Services.GetRequiredService<IDiagnosticAnalyzerService>();
Expand Down Expand Up @@ -286,7 +286,7 @@ private static SortedDictionary<TextSpan, List<DiagnosticData>> ConvertToMap(
{
cancellationToken.ThrowIfCancellationRequested();

using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}");
ImmutableArray<DiagnosticData> diagnostics;

if (textSpan is null)
Expand All @@ -295,7 +295,7 @@ private static SortedDictionary<TextSpan, List<DiagnosticData>> ConvertToMap(
textSpan = new TextSpan(0, text.Length);
}

using (TelemetryLogging.LogBlockTimeAggregatedHistogram(
using (RoslynTelemetry.RecordBlockTime(
FunctionId.CodeFix_Summary, $"{nameof(GetDocumentFixAllForIdInSpanAsync)}.{nameof(IDiagnosticAnalyzerService.GetDiagnosticsForSpanAsync)}"))
{
var service = document.Project.Solution.Services.GetRequiredService<IDiagnosticAnalyzerService>();
Expand Down Expand Up @@ -530,11 +530,11 @@ private async IAsyncEnumerable<CodeFixCollection> StreamFixesAsync(
var logMessage = KeyValueLogMessage.Create(static (m, args) =>
{
var (fixerName, document) = args;
m[TelemetryLogging.KeyName] = fixerName;
m[TelemetryLogging.KeyLanguageName] = document.Project.Language;
m[TelemetryKeys.Name] = fixerName;
m[TelemetryKeys.LanguageName] = document.Project.Language;
}, (fixerName, document));

using var _ = TelemetryLogging.LogBlockTime(FunctionId.CodeFix_Delay, logMessage, CodeFixTelemetryDelay);
using var _ = RoslynTelemetry.LogBlockTime(FunctionId.CodeFix_Delay, logMessage, CodeFixTelemetryDelay);

var codeFixCollection = await TryGetFixesOrConfigurationsAsync(
document, span, diagnostics, fixAllForInSpan, fixer,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -183,7 +183,7 @@ public async Task<ImmutableArray<CodeRefactoring>> GetRefactoringsAsync(
CodeActionRequestPriority? priority,
CancellationToken cancellationToken)
{
using (TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.CodeRefactoring_Summary, $"Pri{priority.GetPriorityInt()}"))
using (RoslynTelemetry.RecordBlockTime(FunctionId.CodeRefactoring_Summary, $"Pri{priority.GetPriorityInt()}"))
using (Logger.LogBlock(FunctionId.Refactoring_CodeRefactoringService_GetRefactoringsAsync, cancellationToken))
{
using var _ = PooledDictionary<CodeRefactoringProvider, int>.GetInstance(out var providerToIndex);
Expand All @@ -208,12 +208,12 @@ public async Task<ImmutableArray<CodeRefactoring>> GetRefactoringsAsync(
var logMessage = KeyValueLogMessage.Create(static (m, args) =>
{
var (providerName, document) = args;
m[TelemetryLogging.KeyName] = providerName;
m[TelemetryLogging.KeyLanguageName] = document.Project.Language;
m[TelemetryKeys.Name] = providerName;
m[TelemetryKeys.LanguageName] = document.Project.Language;
}, (providerName, document));

using (RoslynEventSource.LogInformationalBlock(FunctionId.Refactoring_CodeRefactoringService_GetRefactoringsAsync, providerName, cancellationToken))
using (TelemetryLogging.LogBlockTime(FunctionId.CodeRefactoring_Delay, logMessage, CodeRefactoringTelemetryDelay))
using (RoslynTelemetry.LogBlockTime(FunctionId.CodeRefactoring_Delay, logMessage, CodeRefactoringTelemetryDelay))
{
var refactoring = await @this.GetRefactoringFromProviderAsync(
document, state, provider, cancellationToken).ConfigureAwait(false);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,7 @@ public async Task<ImmutableArray<DiagnosticData>> GetDiagnosticsForSpanInProcess
using var _2 = ArrayBuilder<DiagnosticAnalyzer>.GetInstance(out var semanticSpanBasedAnalyzers);
using var _3 = ArrayBuilder<DiagnosticAnalyzer>.GetInstance(out var semanticDocumentBasedAnalyzers);

using var _4 = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"Pri{priority.GetPriorityInt()}");
using var _4 = RoslynTelemetry.RecordBlockTime(FunctionId.RequestDiagnostics_Summary, $"Pri{priority.GetPriorityInt()}");

foreach (var analyzer in analyzers)
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -216,7 +216,7 @@ async ValueTask<ImmutableArray<DiagnosticData>> GetSyntaxDiagnosticsInProcessAsy

if (_lazySyntaxDiagnostics == null)
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSyntaxDiagnosticsInProcessAsync)}.{nameof(GetAnalysisResultInProcessAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSyntaxDiagnosticsInProcessAsync)}.{nameof(GetAnalysisResultInProcessAsync)}");

var analysisScope = AnalysisScope.WithAnalyzers(_compilationBasedAnalyzersInAnalysisScope);
var syntaxDiagnostics = await GetAnalysisResultInProcessAsync(analysisScope).ConfigureAwait(false);
Expand Down Expand Up @@ -252,7 +252,7 @@ async ValueTask<ImmutableArray<DiagnosticData>> GetSemanticDiagnosticsInProcessA

if (_lazySemanticDiagnostics == null)
{
using var _ = TelemetryLogging.LogBlockTimeAggregatedHistogram(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSemanticDiagnosticsInProcessAsync)}.{nameof(GetAnalysisResultInProcessAsync)}");
using var _ = RoslynTelemetry.RecordBlockTime(FunctionId.RequestDiagnostics_Summary, $"{nameof(GetSemanticDiagnosticsInProcessAsync)}.{nameof(GetAnalysisResultInProcessAsync)}");

var analysisScope = AnalysisScope.WithAnalyzers(_compilationBasedAnalyzersInAnalysisScope);
var semanticDiagnostics = await GetAnalysisResultInProcessAsync(analysisScope).ConfigureAwait(false);
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.

using System.Collections.Generic;
using System.Threading.Tasks;
using Microsoft.CodeAnalysis.Internal.Log;
using Microsoft.CodeAnalysis.Telemetry;
using Microsoft.VisualStudio.Telemetry;
using Microsoft.VisualStudio.Telemetry.Metrics.Events;
using Roslyn.LanguageServer.Protocol;
using Xunit;
using Xunit.Abstractions;

namespace Microsoft.CodeAnalysis.LanguageServer.UnitTests;

/// <summary>
/// Covers the language server's request telemetry end to end: a real LSP request records aggregated
/// measurements, and shutting the server down posts them to the telemetry session.
/// </summary>
public sealed class LanguageServerRequestTelemetryTests(ITestOutputHelper testOutputHelper)
: AbstractLanguageServerHostTests(testOutputHelper)
{
private sealed class RecordingPoster : VSMetricSink.IMetricPoster
{
public List<TelemetryEvent> PostedEvents { get; } = [];

public bool IsOptedIn => true;

public void Post(TelemetryEvent telemetryEvent, TelemetryMetricEvent metricEvent)
=> PostedEvents.Add(telemetryEvent);
}

[Fact]
public async Task RealRequestsProduceAggregatedTelemetry()
{
var poster = new RecordingPoster();
using var sink = VSMetricSink.TestAccessor.CreateSink(poster);
using var registration = RoslynTelemetry.AddMetricSink(sink);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If this was running in parallel with another test, things could go bad right?

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, but we don't run tests in parallel within the same run (we only parallelize at the process level). There's likely much more that is broken if we tried to parallelize within a run.


var server = await CreateLanguageServerAsync();

// Measurements accumulate against instruments; nothing is posted until a flush.
Assert.Empty(poster.PostedEvents);

// Shutting the server down disposes its RequestTelemetryLogger, whose Dispose flushes.
await server.DisposeAsync();

// One event per instrument, and the method tag discriminates buckets: initialize and
// initialized are separate instruments under the same event name.
var durations = poster.PostedEvents.FindAll(e => e.Name == "vs/ide/vbcs/lsp/requestduration");
Assert.Contains(durations, e => Equals(e.Properties["vs.ide.vbcs.lsp.requestduration.method"], Methods.InitializeName));
Assert.Contains(durations, e => Equals(e.Properties["vs.ide.vbcs.lsp.requestduration.method"], Methods.InitializedName));
Assert.All(durations, e => Assert.Equal(
WellKnownLspServerKinds.CSharpVisualBasicLspServer.ToTelemetryString(),
e.Properties["vs.ide.vbcs.lsp.requestduration.server"]));

var counters = poster.PostedEvents.FindAll(e => e.Name == "vs/ide/vbcs/lsp/requestcounter");
Assert.Contains(counters, e => Equals(e.Properties["vs.ide.vbcs.lsp.requestcounter.method"], Methods.InitializeName));

Assert.Contains(poster.PostedEvents, e => e.Name == "vs/ide/vbcs/lsp/timeinqueue");
}
}
Loading