Rationalize and simplify telemetry logging apis by dibarbet · Pull Request #85062 · dotnet/roslyn

dibarbet · 2026-08-27T02:06:29Z

Was trying to make changes to telemetry initialization to better support daemon mode in the language server. However it was difficult due to the rats nest of telemetry types we had. Decided to take a stab at simplifying things

Initialization changes

                 BEFORE                          │                  AFTER
════════════════════════════════════════════════╪══════════════════════════════════════════
 Program.cs                                     │  Program.cs
   var reporter = exportProvider                │    telemetry.InitializeSession(
     .GetExportedValue<ITelemetryReporter>()    │        level, sessionId, isDefault)
   RoslynLogger.Initialize(reporter, ...)       │                    │
              │                                 │                    ▼
              │  static, on a *sink* type       │  LanguageServerTelemetry
              ▼                                 │    session = new TelemetrySession(...)
 RoslynLogger.Initialize                        │    session.Start()
    reporter.InitializeSession(...)  ──┐        │              │
              │                        │        │              ▼
              │   calls back down      │        │    AddEventSink(
              ▼                        │        │        TelemetryLogger.Create(session))
 LanguageServerTelemetryReporter       │        │    AddMetricSink(
    session = new TelemetrySession()   │        │        new VSMetricSink(session))
    session.Start()                    │        │              │
              │                        │        │              ▼
              ▼                        │        │    keep the returned IDisposables
    TelemetryLogger.Create(session,    │        │
                    logDelta: false);  │        │
              │  ^^^ result discarded  │        │
              ▼                        │        │
    TelemetryLogger.Implementation     │        │
              │                        │        │
              ▼                        │        │
    TelemetryLogProvider.Create        │        │
              │                        │        │
              ▼                        │        │
    TelemetryLogging.SetLogProvider    │        │
      installs metrics root            │        │
      starts 30-min flush loop         │        │
              │                        │        │
              └── returns ─────────────┘        │
              │                                 │
              ▼   back up in RoslynLogger       │
    _instance = new RoslynLogger(reporter)      │
    Logger.SetLogger(                           │
      AggregateLogger.Create(                   │
        Logger.GetLogger(),   ← read back       │
        _instance))                             │
════════════════════════════════════════════════╪══════════════════════════════════════════
 7 types, 2 static roots installed,             │  3 types, 1 root, no nesting,
 metrics wired by side effect,                  │  metrics named explicitly,
 must read current state back                   │  teardown is disposing an array

Logging call chain

                 BEFORE                          │                  AFTER
════════════════════════════════════════════════╪══════════════════════════════════════════
  Logger.Log      TelemetryLogging.Log          │   RoslynTelemetry.Log      .Count
  Logger.LogBlock TelemetryLogging.LogAggr…     │   RoslynTelemetry.LogBlock .Record
        │               │            Razor      │   (Logger.X forwards)      .RecordBlockTime
        │               │              │        │          │                     │
        ▼               ▼              ▼        │          └──────────┬──────────┘
   ┌────────┐   ┌──────────────┐  ┌─────────┐   │                     ▼
   │ Logger │   │TelemetryLog- │  │ITelemet-│   │          ┌────────────────────┐
   │        │   │    ging      │  │ryReport-│   │          │  RoslynTelemetry   │
   └───┬────┘   └──────┬───────┘  │   er    │   │          │                    │
       ▼               ▼          └────┬────┘   │          │  IsEnabled first ──┼─► no sink
   ┌────────┐   ┌──────────────┐       │        │          └───┬────────────┬───┘   enabled
   │ILogger │   │ITelemetryLog-│       │        │              ▼            ▼       = no
   └───┬────┘   │   Provider   │       │        │        ┌──────────┐ ┌───────────┐  alloc
       ▼        └──────┬───────┘       │        │        │IEventSink│ │IMetricSink│
   ┌────────┐          ▼               │        │        └────┬─────┘ └─────┬─────┘
   │Aggreg- │   ┌──────────────┐       ▼        │             ▼             ▼
   │ate     │   │TelemetryLog- │ ┌───────────┐  │         the sinks    VSMetricSink
   │Logger  │   │  Provider    │ │Telemetry- │  │             │             │
   │        │   └──────┬───────┘ │ Reporter  │  │             └──────┬──────┘
   │IsEnab- │          ▼         │VSCodeTel- │  │                    ▼
   │led =>  │   ┌──────────────┐ │ Reporter  │  │           ┌─────────────────┐
   │ true   │   │ITelemetryLog │ │ …Wrapper  │  │           │ TelemetrySession│
   │ always │   │ITelemetry-   │ └─────┬─────┘  │           └─────────────────┘
   └───┬────┘   │  BlockLog    │       ▼        │                    ▲
       │        └──────┬───────┘ ┌───────────┐  │         Razor ─────┘  no chain
       │               ▼         │Aggregating│  │                       of its own
       │        ┌──────────────┐ │Telemetry- │  │
       │        │AbstractAggre-│ │   Log     │  │
       │        │gatingLog<,>  │ │ …Manager  │  │
       │        │ ├Counter     │ │ .Counter  │  │
       │        │ └Histogram   │ └─────┬─────┘  │
       │        │VSTelemetryLog│       │        │
       │        │TimedBlock    │       │        │
       │        └──────┬───────┘       │        │
       ▼               │               │        │
   the sinks           │               │        │
       │               │               │        │
       └───────┬───────┴───────────────┘        │
               ▼                                │
     ┌───────────────────┐                      │
     │  TelemetrySession │                      │
     └───────────────────┘                      │
════════════════════════════════════════════════╪══════════════════════════════════════════
 3 parallel chains, up to 6 types deep,         │  1 chain, 2 types deep,
 no short-circuit before allocating             │  short-circuits before allocating

tests - verify oop,lsp,vs have right loggers
manual - verify vs,lsp log, verify etw

Microsoft Reviewers: Open in CodeFlow

Roslyn had eight loosely-coordinated abstractions over a single underlying transport. This collapses the duplicated ones and gives call sites two APIs instead of five. Deleted outright: - RoslynLogger, a byte-for-byte reimplementation of TelemetryLogger for the standalone LSP host. The host already constructed a TelemetryLogger and threw it away; it now registers it. This also closes a consent gap: RoslynLogger gated on "is a reporter configured" rather than IsOptedIn, so an opted-out session still built events and rented pooled property lists. - ITelemetryLog, ITelemetryBlockLog, ITelemetryLogProvider, TelemetryLogging, TelemetryLoggingInterpolatedStringHandler, VisualStudioTelemetryLog, TelemetryLogProvider, TimedTelemetryLogBlock -- four types and four hops to reach a call that is now direct. - AbstractAggregatingLog, AggregatingCounterLog, AggregatingHistogramLog, replaced by one VSMetricSink. - AggregateLogger.AddOrReplace/Remove and the five bespoke ways call sites used them. Composition is now fixed at startup and sinks are toggled through their own IsEnabled predicate, which structurally prevents a sink being registered twice and posting everything twice. - EmptyLogger, which had no callers. Renamed, no shim: ILogger -> IEventSink (it collided with Microsoft.Extensions.Logging.ILogger, which is why call sites needed aliases), AggregateLogger -> AggregateEventSink, Logger.SetLogger/GetLogger -> RoslynTelemetry.SetEventSink/GetEventSink/AddEventSink. Logger.Log and Logger.LogBlock remain as a forwarding shim so the 150+ existing call sites did not have to change here. They carry no [Obsolete] because the repo builds with warnings as errors. Aggregation now buckets by TelemetrySessionKey as well as instrument identity. The key is a constant today, but it means aggregation state is not keyed on the assumption of a single session -- daemon mode currently merges concurrent servers into one bucket, and one server exiting flushes and clears every other live server's partial data. The ~28 metric call sites moved to real tags. Bucket identity is preserved exactly: VSMetricSink builds its dimension key from tag values in declaration order, reproducing the compound strings call sites used to concatenate by hand. This also removes a per-call closure allocation on the LSP request path, where the property-setter lambda captured locals three times per request. Validation: Ide.slnf, Compilers.slnf, Razor.slnf and the CodeStyle package all build clean; new VSMetricSinkTests cover the exactly-one-post-per-flush, bucketing, naming and opt-out invariants; existing LSP and Razor telemetry tests pass unchanged. Razor's own aggregation is left in place -- see .github/memory/known-issues/razor.md. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

…eporter Razor's VS Code extension owns no TelemetrySession -- it posts through the language server host's session via ILanguageServerTelemetryReporterWrapper. Its ReportMetric override flattened the metric event to name + properties: _reporter.Report(metricEvent.Event.Name, metricEvent.Event.Properties) TelemetryMetricEvent pairs a TelemetryEvent (name + dimensions) with an IInstrument holding the aggregated values, and PostMetricEvent is the only thing that reads the instrument. AggregatingTelemetryLog puts exactly one property on its event -- "method" -- so every histogram Razor aggregated in VS Code arrived with a dimension and no measurements at all. The wrapper now forwards the TelemetryMetricEvent intact, so all three Razor hosts emit the same shape. Note this means VS Code starts sending aggregated Razor timings it never actually sent before. Consent still gates it through session.IsOptedIn. With the flattening gone, ITelemetryReporter (the LSP host's, not Razor's) had one member left with a real consumer and one implementation, so it is deleted. LanguageServerTelemetryReporter becomes a concrete export named LanguageServerTelemetryService, matching AbstractWorkspaceTelemetryService in the VS and ServiceHub hosts, and gains PostMetricEvent alongside Log for the Razor bridge. It could not have become an IEventSink: that contract is FunctionId-keyed, whereas this type's jobs are session lifecycle and posting arbitrary string-named events on another component's behalf. Validation: Ide.slnf, Compilers.slnf and Razor.slnf build clean; LSP telemetry tests 18/18 and Razor telemetry tests 19/19 pass. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

LanguageServerTelemetryService.Log and PostMetricEvent existed solely so TelemetryReporterWrapper could forward to them -- nothing in Roslyn's own telemetry used either. That put Razor-bridge translation on the host's telemetry service, one layer away from the only file that needs it. The service now exposes its Session and the wrapper does the posting itself. Ownership is unchanged: the wrapper only reads and posts, disposal stays with the service, so this does not reintroduce the double-dispose hazard that ruled out handing Razor the session via TelemetryReporter.SetSession. LanguageServerTelemetryService is left with session lifecycle only: InitializeSession, Dispose, and the three configuration statics. TestLog is retargeted at the bridge as TestRazorBridgePostsThroughTheHostSession and now covers both directions, including the metric path that previously had no coverage at all. Validation: Ide.slnf, Compilers.slnf and Razor.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Comments explaining what a type or method replaced, or narrating the change that introduced it, are only meaningful against a diff. Replaced with what the code does and why, for a reader starting from a clean checkout. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

AggregateEventSink.IsEnabled returned true unconditionally, so TryGetActiveEventSink always succeeded whenever a composite was registered and every Logger.Log call built a LogMessage -- and LogBlock rented a pooled block and burned a block id -- before the composite's dispatch loop discovered that all of its children were disabled. That is the common case, not a corner: VS composes six sinks and all six are normally off (ETW predicate false, Trace false, CodeMarkers off, TraceSource set empty, File off, and TelemetryLogger false whenever the user is opted out). On a path sized for 1-10k events/second, the pooling exists precisely to avoid that allocation. RoslynTelemetry now holds the sinks itself, so the guard asks whether any sink wants the FunctionId before anything is constructed. Every IsEnabled implementation is a bool read, a predicate call, or a dictionary lookup, so consulting them twice -- once to decide, once per sink while dispatching -- costs far less than what it avoids. Folding the fan-out in also removes the reason AggregateEventSink existed at all. AddEventSink is now an interlocked array append rather than wrapping the existing sink in a new composite, which is what forced Create to flatten nested aggregates and dedupe through a HashSet. And no type is left in the middle that has to answer IsEnabled on behalf of others. RoslynLogBlock captures the sink array at start, so a block still ends on exactly the sinks it started on. Validation: Compilers.slnf builds clean; Ide.slnf and Razor.slnf build clean apart from Microsoft.VisualStudio.Extensibility.Testing.Xunit, which fails identically on a clean tree at HEAD (Arcade RepositoryCommit, unrelated). LSP telemetry tests 18/18, Razor telemetry tests 19/19. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The AsyncLocal session key, s_ambientRoutingEnabled, TelemetrySessionKey, and VSMetricSink.RegisterSession had no callers and CurrentSessionKey always returned Default. Worse, they pre-committed to a shape -- one sink holding many sessions, routed by ambient key -- that made per-session routing hard to reason about, since selecting a session and selecting a destination were two separate half-built mechanisms. A VSMetricSink now covers exactly one TelemetrySession, so the sink instance is the session scope and the aggregation key drops back to (eventName, metricName, dimensions). It no longer registers itself either; the host does that, which is where the rest of its telemetry composition already happens. That leaves IMetricSink as the extension point for multiple sessions: compose one VSMetricSink per session behind an IMetricSink that routes between them and flushes all of them. Nothing in VSMetricSink, RoslynTelemetry, or any call site has to change for that. Also removes GetMetricSink (no callers). GetEventSinks stays: host composition uses it to preserve sinks registered via AddEventSink, and the integration test harness uses it to save and restore. LogBlockTime now guards on whether any sink wants the FunctionId instead of whether any sink exists at all, matching every other entry point. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

…nt sinks The standalone language server never got a metric sink, so every RoslynTelemetry.Count/Record call there silently no-opped -- LSP_RequestDuration, LSP_RequestCounter, LSP_TimeInQueue, LSP_FindDocumentInWorkspace and every aggregated Features/Workspaces metric stopped being reported in that host. It previously got one for free: TelemetryLogger.Create called TelemetryLogProvider.Create, which called TelemetryLogging.SetLogProvider. When that two-stage init went away only VS and OOP were rewired. That same SetLogProvider call also started the 30-minute flush loop, so the language server lost periodic flushing too. VSMetricSink now owns its own flush loop and is IDisposable, so composing a sink is all a host has to remember -- which is the failure mode that produced this bug in the first place. Hosts hold and dispose it. SetEventSinks and AddEventSink previously shared one array, so whichever ran second clobbered the first. That is a real ordering hazard, not a theoretical one: VisualStudioDiagnosticsWindowPackage.InitializeAsync calls PerformanceLoggersPage.SetLoggers, which attaches the output window sink, and nothing orders that against workspace creation. Host-composed and dynamically attached sinks are now separate lists combined on the write path, so neither can clobber the other and a host lists exactly the sinks it owns. GetEventSinks is gone from the public surface as a result; capture and restore moved to a TestAccessor, as did construction over a caller-supplied IMetricPoster. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

SetEventSinks and AddEventSink wrote to one array, so whichever ran second clobbered the first. The previous commit worked around that by splitting host and dynamic sinks into separate lists. Dropping SetEventSinks removes the collision instead: a sink is added, and disposing what Add returns removes it. That is four fields, two verbs and two lifetimes down to one field and one verb. Nothing needs to distinguish "composed by the host" from "attached at runtime" any more, because neither can overwrite the other. The predicate-based AddOrReplace/Remove deleted earlier is not coming back with this: no predicate, no type matching, no nested aggregates to flatten. The caller removes exactly the sink it added. Hosts hold their registrations and dispose them on shutdown, which VS and OOP did not previously do at all. Tests scope theirs with using, so the blanket teardown in UseExportProviderAttribute is now a safety net rather than the mechanism, and the integration test harness drops its capture/restore helper entirely. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

…istration shape LanguageServerTelemetryService shares no type, interface or base with AbstractWorkspaceTelemetryService, and is not a workspace service in the Roslyn sense -- it owns the standalone language server's telemetry session, registers its sinks, and tears them down at shutdown. LanguageServerTelemetryHost says that without implying a relationship that does not exist. SetMetricSink was the last set-and-replace registration left. It is now AddMetricSink returning a registration, matching AddEventSink, so both signals are registered and unregistered the same way and hosts hold both handles. Measurements fan out across registered sinks exactly as events do; a host serving several sessions registers one sink that routes between them, which is the same answer for both signals rather than two different ones. There is only ever one metric sink today, so this buys consistency rather than capability -- but it removes the last place where the two signals had different lifetime rules for no reason. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Both hosts tracked a metric sink, its registration, and their event sink registrations in separate fields, then unwound them one at a time. VSMetricSink is itself IDisposable, so all of it fits one ImmutableArray<IDisposable> ordered the way teardown has to run: registrations first, then the sinks they pointed at. RoslynTelemetry likewise had two near-identical registration types. Both now use one Registration that takes the unregister action, since the only thing that differed was which array to remove from. Also renames LanguageServerTelemetryHost to LanguageServerTelemetry -- the namespace already says LanguageServer, and "Host" collides with LanguageServerHost meaning the server itself. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Both exist solely for the Performance Loggers options page, so they no longer need a mutable predicate or a place in any host's composition: the page registers one when the box is checked and disposes the registration when it is not. TraceLogger goes back to an immutable predicate, OutputWindowLogger loses its singleton and EnsureRegistered, and both hosts drop their _traceLogger field. EtwLogger stays composed. Roslyn.VisualStudio.DiagnosticsWindow is IsShipping=false, so making ETW depend on the options page would mean enabling ETW for a single FunctionId on a customer machine -- the documented vsregedit Roslyn\Internal\Performance\FunctionId workflow -- would require an internal VSIX. Its predicate is a snapshot from FunctionIdOptions.CreateFunctionIsEnabledPredicate rather than a live read, so it still needs refreshing when options change; UpdateDiagnosticSinkEnablement narrows to UpdateEtwEnablement. So there are two mechanisms, but now for a stated reason rather than by accident: composed for what must work without the diagnostics VSIX, registered on demand for what cannot exist without it. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

RemoteWorkspaceTelemetryService never composed an ETW sink: in ServiceHub, ETW only ever existed because the Performance Loggers page pushed it over IRemoteProcessTelemetryService.EnableLoggingAsync. Composing a permanently disabled one there and toggling its predicate added a field, a method and an always-false sink for nothing -- the reason ETW stays composed in devenv (the vsregedit per-FunctionId workflow must work without the non-shipping diagnostics VSIX) does not apply to a process that can only be reached from that VSIX in the first place. So EnableLoggingAsync now registers ETW next to the trace sink and disposes the registration when unchecked, and RemoteWorkspaceTelemetryService is back to composing just the telemetry sink. Also drop the PerfMarginPanel comment about the composition root and state instead why the registration is guarded and never disposed: the tool window can be reopened over the same static model. Validation: Ide.slnf builds clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The [Export, Shared] attribute had been appended to the closing </summary> line. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

azure-pipelines · 2026-08-27T02:06:50Z

Azure Pipelines: Successfully started running 2 pipeline(s). There may be pipelines that require an authorized user to comment /azp run to run.

Dead code: - RecordBlockTime's params-tags overload had no callers, so TimedBlock's tag field and its span/null dance went with it. - minThresholdMs on RecordBlockTime had no non-default caller here or on the API it replaced, LogBlockTimeAggregatedHistogram, so the threshold check was unreachable. TimedBlock is now a primary constructor and a tick. LogBlockTime keeps its threshold; CodeFix_Delay and CodeRefactoring_Delay do pass one. - TelemetryLogger.GetEventName/GetPropertyName were one-line forwarders to TelemetryNaming with a single external caller; FaultReporter now calls TelemetryNaming, which also leaves its Telemetry using unused. - TelemetryNaming.EventPrefix/PropertyPrefix are only read inside the class. - A duplicated using and an unused System.Threading in RoslynTelemetry.Metrics. Comments: - RoslynTelemetry's summary pointed at SetEventSinks/SetMetricSink, which no longer exist. - EtwLogger claimed to stay registered for the process lifetime, which stopped being true for ServiceHub, and DisabledPredicate claimed to be an initial state it is never used as. UpdatePredicate now states why a snapshot predicate has to be swapped at all. - Dropped three IEventSink doc comments that restated the method name; LogBlockStart/LogBlockEnd instead say what uniquePairId and delta are. - Deduplicated VSMetricSink: the flush lock and the test accessor each explained themselves twice, and the class summary said Flush posts and clears immediately after saying measurements are posted by Flush. - Dropped "rather than" phrasings and comments that narrated the code: VSCodeTelemetryReporter announcing two overrides, Program.cs describing what Dispose does internally. Validation: Ide.slnf and Compilers.slnf build clean; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Blocking: - The standalone language server passed logDelta: false, so block end events silently lost vs.ide.vbcs.<id>.delta. The deleted RoslynLogger passed the delta unconditionally -- it had no logDelta concept -- and the option that gates it in devenv has no counterpart in that host. - RoslynTelemetry.Workspaces.cs referenced RecordBlockTime(FunctionId, string, int), which stopped existing when the unused threshold parameter was removed. CS1574 is not in the repo's NoWarn, so this broke a warnaserror build. Telemetry fidelity: - TimedBlock and TimedEventBlock timed with Environment.TickCount, quantized to ~15.6ms. Every aggregated duration histogram measures sub-100ms IDE operations, so a 3ms code fix pass recorded 0 or 15. The deleted TimedTelemetryLogBlock used SharedStopwatch; both now do again. - That same type suppressed recording in debug bits and under a debugger, and it served the aggregated path too (AggregatingHistogramLog.LogBlockTime returned one). Only the discrete path kept the guard; RecordBlockTime now has it as well, so a breakpoint inside GetMostSevereFixAsync no longer contributes a multi-second sample. Correctness: - Log(FunctionId, LogMessage) freed the pooled message only when a sink was enabled. Callers migrated from TelemetryLogging.Log, which always freed, leaked one message per call -- including PerformanceTrackerService in the OOP process, where no event sink is normally registered. - A block ended on whichever sinks were enabled at dispose, not on the ones it started on, so a sink enabled mid-block received an end with no start. TelemetryLogger asserts the pending scope exists, so that throws; the opposite flip leaks the scope. RoslynLogBlock now records which sinks got the start and ends on exactly those. - VSMetricSink.Flush exchanged the aggregation map before posting, so a concurrent Count/Record missed and built a second instrument with the same name on the same meter while the first was being posted -- the shape of dotnet#71606. Cleared after the loop again, as before. - AggregationKey ignored counter-vs-histogram, so one event and metric name used both ways would hand a counter to an IHistogram cast. The old design kept separate dictionaries and could not express this. - An exception from Flush escaped the 30-minute loop, whose task nobody observes, silently ending all later flushes for the session. Also: guard LanguageServerTelemetry's Report/Flush on having a session, since MEF disposes it a second time and the session reporters are not idempotent; drop PerfMarginPanel's registration guard, which AddEventSink already provides and which prevented re-registration after tests clear sinks; remove four dead consts; correct the VS Code Razor ReportMetric comment, which claimed a data loss that cannot occur because that reporter never builds a session manager. Adds RoslynTelemetryTests covering the pairing contract. Validation: Ide.slnf and Compilers.slnf build clean; Workspaces telemetry tests 6/6 on net10.0 and net472; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The loop reads the token on every iteration, so a source disposed while Flush is running would throw ObjectDisposedException into the new catch-all and spin rather than stop. Cancelling is enough; the loop now also checks the flag. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The reason it was composed at startup does not survive checking. The comment on FunctionIdOptions.CreateOption advertises vsregedit set local [hive] HKCU Roslyn\Internal\Performance\FunctionId [name] dword 1 but the option's config name is "FunctionIdOptions_" + name and there is no FunctionIdOptions_* entry in VisualStudioOptionStorage.Storages. VisualStudioOptionPersister.TryFetch opens with Storages.TryGetValue, so the fetch misses and the value falls through to the default, false; TryPersist misses the same dictionary, so it is not written back either. Contrast visual_studio_etw_logger_key, which does have a LocalUserProfileStorage entry. The only writers of a FunctionIdOptions value are PerformanceFunctionIdPage and PerformanceLoggersPage, both in Roslyn.VisualStudio.DiagnosticsWindow. So without that non-shipping VSIX no FunctionId is ever enabled, and the composed sink's predicate is false forever -- it cannot serve the support scenario it was kept for, because that scenario does not currently work at all. Registering it from the options page alongside the trace and output window sinks therefore loses nothing observable and collapses registration back to one mechanism: composed for what a host always wants, registered on demand for what only the diagnostics VSIX turns on. EtwLogger returns to an immutable predicate, and DisabledPredicate, UpdatePredicate, _etwLogger, UpdateEtwEnablement and the downcast reaching from the VSIX into the shipping assembly all go with it. If the vsregedit workflow is wanted, the fix is a Storages entry, separately -- and with a fresh sink built per apply a live option would take effect without restarting, which a snapshot cannot. Also from review: - TelemetryLogger.LogBlockEnd asserted the pending scope exists, but LogBlockStart stores it inside a swallowing try, so a failure from Start left the bit set and no scope -- turning a swallowed error into a thrown one on an arbitrary Roslyn path. It now returns instead. - VSMetricSink.Flush removes each key while holding that aggregation's lock rather than clearing at the end, so measurements recorded under a new key during a flush survive to the next one. The key stays present for the whole post, so a concurrent Count/Record still blocks rather than building a second instrument with the same name. - RoslynLogBlock's bitmask is bounded by its width. Past it a shift would alias onto bit 0 and hand another sink an unpaired end, which is what the bitmask exists to prevent. - RecordingSink now answers only for TestEvent_NotUsed, so unrelated logging from workspace code cannot land in a test's assertions. Adds a test that block duration reaches the event as a delta property only when the sink asked for it, which is the regression fixed in the previous commit, and makes VSMetricSink's two name derivations internal so they can be pinned directly. Validation: Ide.slnf and Compilers.slnf build clean; Workspaces telemetry tests 10/10 on net10.0 and net472; LSP telemetry tests 18/18. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

RecordBlockTime takes no tags while Count and Record do, so its call sites still build compound metric names by hand. Say why in the doc: migrating would repartition existing buckets, which is the one thing this change is careful not to do. RoslynLogBlock's bitmask records which sinks were started, not where a sink routed that start. Note what a future per-session routing sink owes as a result, since a block is a plain IDisposable and can be disposed on a different execution context than it was created on. Adds the two VSMetricSink assertions with the most Kusto value: the meter and property name derivations, pinned as pure functions, and that a counter and a distribution sharing one event and metric name resolve to separate instruments. Validation: Ide.slnf builds clean; Workspaces telemetry tests 10/10 on net10.0 and net472; VSMetricSink tests 6/6. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The comments now describe what the code does, not what someone might do to it later: the Logger shim no longer says when it should be deleted, RecordBlockTime states that its metric name is the whole bucket without arguing about migrating it, RoslynLogBlock's bitmask documents the invariant it enforces without speculating about routing sinks, and the Razor bridge states that ReportMetric is unreachable in that host rather than "not yet". Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

VSCodeRequestTelemetryLogger was exported as a stateless LSP service, and LspServices only tracks non-stateless services for disposal: // Stateless LSP services will be disposed of on MEF container disposal. var checkDisposal = !lazyService.Metadata.IsStateless && !lazyService.IsValueCreated; So RequestTelemetryLogger.Dispose never ran on shutdown in the standalone host, and its own comment -- "Ensure that telemetry logged for this server instance is flushed before potentially creating a new instance" -- was not honored there. The VS host was unaffected: RequestTelemetryLoggerFactory is an ExportCSharpVisualBasicLspServiceFactory, which is stateful. Nothing was lost, since the process-wide sink still flushed on its timer and at process exit, but in daemon mode a server's telemetry was never attributed to its own shutdown. Exporting it through a factory matches the VS host and gives each server its own logger, which is also what the per-server ServerTypeName implies. Adds two tests: - LanguageServerRequestTelemetryTests drives a real language server, then shuts it down and asserts the aggregated request telemetry reaches the session. Verified non-vacuous: it fails against the stateless export. It also pins that the method tag splits buckets -- initialize and initialized produce separate instruments under one event name. - ServiceHubServicesTests_Telemetry drives InitializeTelemetrySessionAsync over the brokered service and asserts the remote host's connect event reaches the sinks that call configured. Validation: LSP telemetry tests 21/21; OOP telemetry test passes on net472. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The previous version drove InitializeTelemetrySessionAsync, which starts a real TelemetrySession; that reaches TelemetryManifestManager and RemoteControlClient, so it attempts network access and cannot run under CI network isolation. EnableLoggingAsync needs no session, and it is the API this change actually rewrote -- ETW and trace sinks in the OOP process are now registered while enabled and unregistered when not, rather than composed with a mutable predicate. The test observes registration through whether anything is listening for a FunctionId, which is the same short-circuit that makes logging free when nothing is; Trace output is not usable because the test host captures no listeners. Verified non-vacuous: it fails if the registration is not disposed when logging is turned back off. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

The unpaired-block hazard it addressed is not caused by this change: the AggregateLogger it replaced re-evaluated IsEnabled in both LogBlockStart and LogBlockEnd exactly the same way. Fixing it here was scope creep, and the bitmask carried its own cost -- a width constant, two Math.Min bounds, and a silent "a sink past the width gets nothing" rule that existed only to make the mask safe. RoslynLogBlock now differs from the original only where it has to: it holds the sink array instead of one ILogger, and runs the per-sink IsEnabled loops that AggregateLogger used to run. TelemetryLogger.LogBlockEnd keeps its graceful return. That one is a regression this change introduced rather than a pre-existing issue: the standalone host used to log through RoslynLogger, whose LogBlockEnd returned when the scope was missing, and consolidating onto TelemetryLogger subjected it to a Contract.ThrowIfFalse instead. Drops the two tests that asserted the reverted behavior; the ones covering sinks registered mid-block, fan-out, registration disposal, and the pooled message contract still hold. Validation: Compilers.slnf builds clean; Workspaces telemetry tests 8/8 on net10.0 and net472; LSP telemetry tests 21/21. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Trims or rewords the doc comments called out in review: shorter summaries on RoslynTelemetry, IEventSink, IMetricSink, TelemetryNaming, Logger, LanguageServerTelemetry, VSMetricSink and the Razor bridge, and removes the ones that restated the code or explained a decision rather than the behavior. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

A measurement that resolved an aggregation just before a flush retired it landed in the retired one and was never posted. Count and Record now re-check under the aggregation lock that they still hold the live aggregation for the key, and retry if a flush replaced it. The two also collapse into one Update, since the only difference left was which instrument method to call. AggregationKey carries an InstrumentKind rather than a bool named for one of its two values, so the switch that builds the instrument reads as the pair it is. GetMeterName and GetPropertyName move to TelemetryNaming, which is where the vs/ide/vbcs convention already lives; they were the second place it was implemented. Adds a test for the race, driven from IMetricPoster.Post, which is the one point a concurrent Count is guaranteed to be blocked on the aggregation lock. Verified non-vacuous: it fails without the re-check. Validation: Ide.slnf builds clean; LSP telemetry tests 22/22; Workspaces telemetry tests 8/8 on net10.0 and net472. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

Copilot

Copilot review overview

🔵 Needs a closer look

Review tier: Lite
Findings: None

Issues resolved since last review (4)

Severity	Finding
	`src/VisualStudio/VisualStudioDiagnosticsToolWindow/PerfMargin/PerfMarginPanel.cs` — PerfMarginPanel calls RoslynTelemetry.AddEventSink(s_logger) on every construction and discards the… View resolved comment
	`src/VisualStudio/Core/Def/Telemetry/Shared/VSMetricSink.cs` — BuildDimensionKey only concatenates tag values with '.' separators. Different tag sets can… View resolved comment
	`src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.Metrics.cs` — AddMetricSink has the same issue as AddEventSink: if the sink is already registered, the returned… View resolved comment
	`src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.cs` — AddEventSink claims to ignore already-registered sinks, but the returned IDisposable always… View resolved comment

Suppressed comments (2)

Previously missed (1) — in code that hasn't changed since the last review.

src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.LogBlock.cs:56

RoslynLogBlock re-checks sink.IsEnabled at both start and end. If a sink’s IsEnabled result changes while a block is in flight (e.g. activity sink gains/loses listeners), the sink can observe an unpaired Start or an unpaired End. This can leave per-sink state inconsistent (e.g. pending-scope tables) and makes block logging harder to reason about. Consider snapshotting which sinks were enabled at Construct time (e.g. a bitmask over the ImmutableArray indices) and using that same snapshot for both LogBlockStart and LogBlockEnd.

src/VisualStudio/Core/Def/Telemetry/Shared/VSMetricSink.cs:237

BuildDimensionKey only incorporates tag values, not tag keys. That means measurements with different tag names but identical values (or values containing '.') can collide into the same AggregationKey and end up being posted with the wrong property set (properties are taken from the first-created aggregation). Include tag keys (and a less ambiguous separator) in the discriminator to avoid cross-bucket contamination.

Copilot

Copilot review overview

🟡 Changes recommended

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Review tier: Lite
Findings: 1

New issues introduced by this change (1)

Severity	Finding
	`src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.cs` — RoslynTelemetry.cs uses Contract/ReferenceEqualityComparer but doesn’t import Roslyn.Utilities in…

Suppressed comments (1)

Previously missed (1) — in code that hasn't changed since the last review.

src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.LogBlock.cs:64

RoslynLogBlock.Dispose() bails out when _sinks is empty, which would skip freeing the LogMessage and returning the block to the pool if CreateLogBlock were ever called with an empty sink array. Use _logMessage == null as the dispose sentinel instead so disposal remains safe even with an empty sink set.

+using System;
+using System.Collections.Generic;
+using System.Collections.Immutable;
+using System.Threading;
+


jasonmalinowski · 2026-09-01T20:47:13Z

+    /// <summary>
+    /// Adds <paramref name="delta"/> to a monotonically increasing counter.
+    /// </summary>
+    void Count(string eventName, string metricName, long delta, ReadOnlySpan<KeyValuePair<string, object?>> tags);


Should this be "Add" instead of count?

I personally prefer Count as it makes it clear its a counter. I'm not sure I am happy with Record as the histogram aggregation name though.

Maybe "AddTCount" and "RecordForHistogram" just to make it really obvious then?

jasonmalinowski · 2026-09-01T20:47:56Z


 /// <summary>
-/// provide a way to log activities to various back end such as etl, code marker and etc
+/// Forwarding shim onto <see cref="RoslynTelemetry"/>.


Is this something we'd remove as a follow-up?

yes, I plan to

jasonmalinowski · 2026-09-02T01:02:08Z

+/// </summary>
+public sealed class VSMetricSinkTests
+{
+    private sealed class RecordingPoster : VSMetricSink.IMetricPoster


Should this be in the VS layer tests since the code itself is?

the sink is a shared file, tests here seem OK. open to moving if you feel strongly

I guess I was thinking if the file is at least physically in the VS layer, keep the tests in the same physical layer. Not critical though.

Rename event sink implementations, simplify language server telemetry ownership, make the flush race test deterministic, and add span metric overload coverage. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot

Copilot review overview

🔵 Needs a closer look

It’s a wide, cross-host telemetry refactor with subtle lifecycle/concurrency semantics, and at least one sink pairing correctness concern was identified that should be addressed/validated by the author and a human reviewer.

Review tier: Lite
Findings: 1

Pre-existing issues (1)

Severity	Finding
	`src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.cs` — RoslynTelemetry.cs uses Contract/ReferenceEqualityComparer but doesn’t import Roslyn.Utilities in… View comment

Suppressed comments (1)

src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry_LogBlock.cs:75

RoslynLogBlock checks sink.IsEnabled(...) again on Dispose before calling LogBlockEnd. If a sink was enabled at block start but becomes disabled before Dispose, it will receive a start without a matching end. For sinks that track in-flight scopes (e.g., TelemetryEventSink keeps a _pendingScopes entry per start), skipping the end can leak that state and break pairing. Consider recording which sinks actually received LogBlockStart (e.g., bitmask by index for small sink counts, or a filtered sink list) and always calling LogBlockEnd for that same set, without re-checking IsEnabled at the end.

jasonmalinowski · 2026-09-02T22:43:57Z

+- Name concrete `IEventSink` implementations with the `EventSink` suffix. Visual Studio implementations
+  live under `src/VisualStudio/Core/Def/Telemetry/`; `TelemetryEventSink` and `VSMetricSink` are source-linked
+  into the Language Server and ServiceHub hosts.
+- Name `RoslynTelemetry` partial files with an underscore, such as


This rule should apply generally, not just for RoslynTelemetry.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot

Copilot review overview

🟡 Changes recommended

The Razor telemetry bridge posts directly to VS telemetry without exception shielding, which can crash the language server on telemetry/session shutdown races.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Review tier: Lite
Findings: 2

New issues introduced by this change (1)

Severity	Finding
	`src/LanguageServer/Microsoft.CodeAnalysis.LanguageServer/HostWorkspace/Razor/TelemetryReporterWrapper.cs` — Telemetry posting should be best-effort; `TelemetryEventSink` intentionally swallows exceptions…

Pre-existing issues (1)

Severity	Finding
	`src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.cs` — RoslynTelemetry.cs uses Contract/ReferenceEqualityComparer but doesn’t import Roslyn.Utilities in… View comment

Suppressed comments (1)

src/LanguageServer/Microsoft.CodeAnalysis.LanguageServer/HostWorkspace/Razor/TelemetryReporterWrapper.cs:36

ReportMetric should also be best-effort and not allow telemetry infrastructure failures to throw back into Razor/LS callers (consistent with TelemetryEventSink swallowing exceptions around metric/event posting).

    public void ReportMetric(TelemetryMetricEvent metricEvent)
        => telemetryService?.Value.Session?.PostMetricEvent(metricEvent);

+        var telemetryEvent = new TelemetryEvent(name);
+        foreach (var property in properties)
+            telemetryEvent.Properties.Add(property);
+
+        session.PostEvent(telemetryEvent);


dibarbet and others added 14 commits August 26, 2026 16:04

Revert documentation changes

6381484

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 4c5bb045-3aa8-4014-bc0c-d5a968389dee

dotnet-policy-service Bot added VSCode Area-Razor labels Aug 27, 2026

This comment was marked as outdated.

Sign in to view

dibarbet and others added 10 commits August 26, 2026 19:57

only allow sink to be registered once

50d3af4

Copilot AI review requested due to automatic review settings August 31, 2026 22:47

Copilot started reviewing on behalf of dibarbet August 31, 2026 22:48 View session

sort

0397ff8

Copilot AI reviewed Aug 31, 2026

View reviewed changes

Copilot AI review requested due to automatic review settings August 31, 2026 22:56

Copilot started reviewing on behalf of dibarbet August 31, 2026 22:57 View session

Copilot AI reviewed Aug 31, 2026

View reviewed changes

Comment thread src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Log/RoslynTelemetry.cs

Comment on lines +5 to +9

using System;

using System.Collections.Generic;

using System.Collections.Immutable;

using System.Threading;

jasonmalinowski reviewed Sep 2, 2026

View reviewed changes

dibarbet and others added 3 commits September 2, 2026 12:21

potential simplification for flush lock

0da1307

simplify tests

f203195

Copilot AI review requested due to automatic review settings September 2, 2026 21:05

dibarbet requested a review from a team as a code owner September 2, 2026 21:05

Copilot started reviewing on behalf of dibarbet September 2, 2026 21:06 View session

Copilot AI reviewed Sep 2, 2026

View reviewed changes

jasonmalinowski reviewed Sep 2, 2026

View reviewed changes

jasonmalinowski approved these changes Sep 2, 2026

View reviewed changes

Address metric sink review feedback

aca50e9

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot AI review requested due to automatic review settings September 3, 2026 00:11

Copilot started reviewing on behalf of dibarbet September 3, 2026 00:12 View session

Copilot AI reviewed Sep 3, 2026

View reviewed changes

jasonmalinowski approved these changes Sep 3, 2026

View reviewed changes

dibarbet merged commit c501c4f into dotnet:main Sep 3, 2026
23 checks passed

dibarbet deleted the dibarbet-telemetry-consolidation branch September 3, 2026 17:03

dotnet-policy-service Bot added this to the Next milestone Sep 3, 2026

This was referenced Sep 4, 2026

[main] Source code updates from dotnet/roslyn dotnet/dotnet#9040

Merged

[release/11.0.1xx] Source code updates from dotnet/roslyn dotnet/dotnet#9047

Merged

dibarbet mentioned this pull request Sep 4, 2026

Update roslyn to 5.12.0-1.26453.19 dotnet/vscode-csharp#9731

Merged

dotnet-bot mentioned this pull request Sep 8, 2026

[Automated] PRs inserted in VS build main-12208.01 #85205

Closed

Uh oh!

Conversation

dibarbet commented Aug 27, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Initialization changes

Logging call chain

Microsoft Reviewers: Open in CodeFlow

Uh oh!

azure-pipelines Bot commented Aug 27, 2026

Uh oh!

This comment was marked as outdated.

This comment was marked as outdated.

Copilot AI left a comment

Choose a reason for hiding this comment

Copilot review overview

🔵 Needs a closer look

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Copilot review overview

🟡 Changes recommended

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Copilot review overview

🔵 Needs a closer look

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Copilot review overview

🟡 Changes recommended

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

dibarbet commented Aug 27, 2026 •

edited

Loading