Expose project evaluation measurements through EventSource

[AlesProkop]

Context

Alternative to #14458 for #14419: expose project evaluation measurements without adding a System.Diagnostics.DiagnosticSource dependency on .NET Framework.

Changes

• Add evaluation and completed-pass events to the existing Microsoft-Build EventSource, enabled by the dedicated EvaluationMeasurements keyword (0x4).
• Include durations, requested stage, build-submission origin, and evaluation success/failure. Each total completion event represents one evaluation count.
• Cover all six evaluation passes, including deferred item realization, while preserving existing tracing events and their ordering.
• Skip timing and payload work when measurements are disabled. A total duration is NaN when collection starts after evaluation begins; incomplete pass measurements are omitted.

Events can be consumed through ETW or an in-process EventListener. PerfStar collector changes are separate. Experimental VS performance validation is pending.

Testing

• Full repository build: passed, no warnings or errors.
• EvaluationEventSource_Tests: 10 passed on net11.0 and 10 passed on net472.
• Bootstrap SDK sample build: passed.

[Copilot]

🔵 Needs a closer look

Make general-event guards keyword-aware to avoid unrelated evaluation overhead when only measurement events are enabled.

Pull request overview

This pull request adds opt-in EventSource measurements for project evaluations and all six evaluation passes without adding a DiagnosticSource dependency.

Changes:

• Adds the EvaluationMeasurements keyword and completion events.
• Instruments durations, stages, origins, and success/failure status.
• Adds cross-target EventListener coverage for event behavior and ordering.

Moderate review finding: keyword-only enablement can trigger unrelated hot-path payload work through parameterless IsEnabled() guards; these guards should be keyword-aware.

File summaries

File	Reviewed changes
src/Framework/MSBuildEventSource.cs	Defines measurement keywords and events.
src/Build/TelemetryInfra/EvaluationInstrumentation.cs	Implements guarded timing and payload emission.
src/Build/Microsoft.Build.csproj	Includes the instrumentation source.
src/Build/Evaluation/Evaluator.cs	Instruments evaluations and passes.
src/Build.UnitTests/Evaluation/EvaluationEventSource_Tests.cs	Tests event contracts and measurement behavior.

Review details

Suppressed comments (1)

src/Framework/MSBuildEventSource.cs:40

• Enabling only this new keyword still makes parameterless MSBuildEventSource.Log.IsEnabled() guards return true. Existing hot paths such as LazyItemEvaluator.IncludeOperation then build payloads (for example string.Join for every glob) and call ExpandGlob* even though Keywords.All is disabled, adding unrelated evaluation overhead to measurement-only consumers. Make the general-event guards keyword-aware (or otherwise isolate this family) before adding the dedicated keyword.

            public const EventKeywords EvaluationMeasurements = (EventKeywords)0x4;

• Files reviewed: 5/5 changed files
• Comments generated: 0
• Review effort level: Lite

---

💡 Add a code-review agent skill for context-aware, tailored reviews. Learn more in the docs.

[baronfel]

This looks easier to use, especially for tools that don't automatically correlate start/stop events like perfview does. Is there a reason to not include the project file name/configuration id on the events, though? It can be useful to know which project/variant of a project is taking X amount of time.

[AlesProkop]

This looks easier to use, especially for tools that don't automatically correlate start/stop events like perfview does. Is there a reason to not include the project file name/configuration id on the events, though? It can be useful to know which project/variant of a project is taking X amount of time.

You are right, added.

[ViktorHofer]

Expert MSBuild review — 24 dimensions

Nice, focused feature: the opt-in keyword, the IsEnabled() short-circuit, and the contract test pinning payload names/types are all the right instincts. Findings below; no blocking issues.

Two findings initially raised as BLOCKING were validated with repros and downgraded — details at the end so they aren't re-litigated.

#	Dimension	Verdict
18	Documentation Accuracy	2 MAJOR
4	Test Coverage	3 MODERATE
6	Logging & Diagnostics	1 MODERATE
10	Design Before Implementation	1 MODERATE
13	Concurrency & Thread Safety	1 MODERATE
20	Scope & PR Discipline	1 MODERATE
3, 12, 14, 16, 21, 22	Perf / Simplification / Naming / Idiomatic C# / Evaluation Model / Correctness	NIT

12/24 dimensions clean — Backwards Compatibility, ChangeWave, Error Messages, String Comparison, API Surface, Target Authoring, Cross-Platform, SDK Integration, File I/O, Build Infrastructure, Dependencies, Security.

• Documentation — documentation/specs/event-source.md not updated; two of its statements are now false
• Documentation — evaluationId documented as "node-local"; it is per-LoggingService
• Logging / Design — permanent, process-wide, silent s_disabled kill switch
• Design / Simplification — helper takes engine objects instead of the already-cached primitives
• Test Coverage — duration assertions too weak; kill switch and constructor-failure path untested
• Scope — no linked issue/spec for a permanent machine-consumed ETW contract

---

NITs (not worth inline comments)

• Naming (14). StartMeasurement/EndPassMeasurement are an asymmetric pair — one returns a long timestamp serving both total and pass, the other returns double seconds and only serves passes; there is no EndMeasurement. GetTimestampIfEnabled() / GetElapsedSecondsIfEnabled() would read better. Separately, ProjectEvaluationCompleted / ProjectEvaluationPassCompleted sit on the same provider as EvaluateStart/EvaluateStop/EvaluatePass5Stop and next to the unrelated logging type ProjectEvaluationFinishedEventArgs; ...Measurement would signal "measurement record" rather than "lifecycle event". Worth deciding now — MeasurementEventsHaveStableOptInContract pins these names as a contract the moment this merges.
• Idiomatic C# (16). RecordEvaluation's evaluationLoggingContext should be EvaluationLoggingContext?. The body already uses ?., and Evaluator.Evaluate's new catch deliberately passes null, so the non-nullable annotation contradicts a supported call path — which is why the test needs null!. (src/Directory.Build.props enables nullable project-wide.)
• Simplification (12). Fold the latch into the enablement helper and drop the four duplicated guards:

  private static bool IsEnabled()
      => Volatile.Read(ref s_disabled) == 0
          && MSBuildEventSource.Log.IsEnabled(EventLevel.Informational, MSBuildEventSource.Keywords.EvaluationMeasurements);

  Also drop the redundant = 0 on pass0MeasurementStart / pass3MeasurementStart.
• Performance (3). Both events bind to the params WriteEvent fallback — measured 216 B (113) and 192 B (114), ~1.4 KB per full evaluation, enabled path only. WriteEventCore with stack-allocated EventData would remove it. Consistent with existing convention — MSBuildEventSource.cs uses WriteEventCore zero times today — so this is optional and arguably belongs to a separate sweep of the whole file. Keyword-off cost measured at 83–93 ns/evaluation, which is fine.
• Evaluation Model (21). Pass 5 alone ends its measurement and emits RecordPass inside the EvaluationPass.Targets profiler scope; the other five emit outside. See the downgrade note below.

---

Downgraded findings (validated with repros — recorded so they aren't re-raised)

evaluationId collisions — BLOCKING → MODERATE, and only the doc needs fixing.
The IDs really do collide: two ProjectCollections in one process both emit 3; UnregisterAllLoggers() (whose own comment notes "VS unregisters all loggers on the same project collection often") resets IDs within one collection; two sequential BuildManager builds both emit 4. But correlation still works — Evaluator.cs contains no await/Task/async, so all 7 events of an evaluation stay on one thread, and a repro confirmed 6 distinct (evaluationId, OSThreadId) groups of exactly 7 events each (6×114 + 1×113 terminator). OSThreadId is on every ETW/EventPipe record. So (PID, TID, evaluationId) disambiguates, and the fix is documentation, not a payload change — adding a 7th field would break the contract test for no practical gain.

Profiler-scope skew — BLOCKING → NIT, and pre-existing.
RecordPass for the targets pass runs inside the EvaluationPass.Targets profiler frame, so its cost is charged to that pass. But MSBuildEventSource.Log.EvaluatePass5Stop was already the last statement inside that same frame before this PR, and a probe reproduced identical skew using the untouched event 24. Realistic cost measured at 0.174 µs (keyword off) / 0.373 µs (in-proc listener) per call — a <0.01% bias on a 1–50 ms pass, below the profiler's own Stopwatch overhead. It also needs -profileevaluation and keyword 0x4 enabled simultaneously. Optional tidy-up: move EndPassMeasurement/EvaluatePass5Stop/RecordPass below the closing brace so all six passes behave alike.

Also checked and found clean: net472 EventSource construction (ConstructionException null, all six payload types round-trip correctly — so the existing Microsoft-Build provider is not at risk); Keywords.All consumers; PerformanceLogEventListener (enables only 0x2, unaffected); PII exposure (events 11–24 already emit full project paths, and no in-repo listener enables 0x4); EnableDefaultItems=false means the explicit <Compile Include> is required and correct for both TFMs; full build 0 warnings/0 errors.

_{Generated by the repo's reviewing-msbuild-code skill — 24 dimensions, per-dimension agents, findings independently validated before posting. Please push back on anything that misreads intent.}