Skip to content

MSBuild server discards the build telemetry event; make telemetry testable #55749

Description

@JanProvaznik

Summary

The MSBuild server discards the dotnet/cli/msbuild/build telemetry event. PR #55582 did not correct this error. I verified this condition with an SDK build that contains that PR.

This issue has two parts:

Part Result
1 The telemetry is correct when the MSBuild server is on.
2 A test finds this class of error. A contributor gets a signal to test each new event.

Part 1 is a defect. Part 2 prevents the next defect of the same type.

Part 1: Correct the telemetry when the server is on

The measurement

I used two SDK builds. One build is before PR #55582. The other build is after it.

SDK Build date Contains PR #55582
11.0.100-preview.7.26357.101 2026-07-07 no
11.0.100-rc.1.26411.119 2026-08-11 yes

I confirmed the presence of the correction in the second build. The dotnet.dll file of that SDK contains the members OnBuildStarted, StopActivity, _initializedTelemetryClient, and WaitForPendingEvents. PR #55582 added each of these members.

The collector is the Aspire dashboard, version 13.4.6:

dotnet tool install -g Aspire.Cli --version 13.4.6

aspire dashboard run --frontend-url http://127.0.0.1:18890 ^
                     --otlp-http-url http://127.0.0.1:14320 ^
                     --allow-anonymous --non-interactive --nologo

Each trial used these steps:

  1. Run dotnet build-server shutdown. This step removes each MSBuild process of a previous trial.
  2. Run dotnet build --no-incremental with the variables below.
  3. Wait for the export operation. Then read GET /api/telemetry/spans?limit=1000.
DOTNET_CLI_TELEMETRY_OPTOUT=false
DOTNET_CLI_TELEMETRY_ENABLE_EXPORTER=1
OTEL_EXPORTER_OTLP_ENDPOINT=http://127.0.0.1:14320
OTEL_EXPORTER_OTLP_PROTOCOL=http/protobuf
DOTNET_CLI_TELEMETRY_SHUTDOWN_TIMEOUT_MS=15000

The result with the SDK that contains PR #55582:

Trial dotnet/cli/msbuild/build
MSBUILDUSESERVER=0 1
MSBUILDUSESERVER=1 0

The control: in the trial with the server, three conditions were true. The build returned exit code 0. An MSBuild server process was present after the build. The events dotnet/cli/toplevelparser/command, dotnet/cli/sublevelparser/command, and dotnet/cli/command/finish arrived over the same connection. Thus the export operation is correct and the network is correct. Only the build event is absent.

The cause

The TelemetryClient.TrackEventTask method attaches each event to the current activity:

var @event = new ActivityEvent($"dotnet/cli/{eventName}", tags: MakeTags(properties));
Activity.Current?.AddEvent(@event);

If Activity.Current is null, the ?. operator discards the event.

PR #55582 added an activity for each build. MSBuildLogger.OnBuildStarted starts this activity. MSBuildLogger.OnBuildFinished stops it.

But MSBuild sends the build event after the BuildFinished event. The BuildManager.cs file shows this sequence:

Line Operation
1204 loggingService.LogBuildFinished(_overallBuildSuccess)
1230 loggingService.LogTelemetry(buildEventContext: null, _buildTelemetry.EventName, ...)

Thus this sequence occurs:

  1. LogBuildFinished sends BuildFinished.
  2. MSBuildLogger.OnBuildFinished calls StopActivity. The activity of the build stops.
  3. LogTelemetry sends the build event. The activity is not present now.

The behavior after step 2 is different in each host:

  • In the CLI process the activity has a parent activity in the same process. After the stop operation, Activity.Current is the parent activity. Thus the event goes to the parent activity.
  • In the MSBuild server process the activity has no parent activity in the same process. Its parent is a remote context. After the stop operation, Activity.Current is null. Thus the code discards the event.

The evidence for this cause

The exported data of the trial without the server shows the two activities. The build event is not on the activity of the build. It is on the parent activity:

SPAN 'invocation'
   - dotnet/cli/msbuild/build              <- the build event is on the PARENT
SPAN 'msbuild'                             <- the activity that PR #55582 adds
   - dotnet/cli/msbuild/loggingConfiguration
   - dotnet/cli/msbuild/targetframeworkeval
   - dotnet/cli/msbuild/targetframeworkeval
   - dotnet/cli/msbuild/build/tasks/taskfactory
   - dotnet/cli/msbuild/build/tasks

The other MSBuild events are on the msbuild activity. MSBuild sends these events during the build. Thus the activity is present for them.

Only the build event is on the parent activity. This position shows that the activity was already stopped when the build event arrived.

The CLI process has a parent activity, thus the event survives. The server process has no parent activity, thus the event does not survive. This difference explains each measurement above.

Two results of this cause

  1. The server discards the build event. This result is the defect in this issue.
  2. The CLI process puts the build event on the wrong activity. The event is on invocation and not on msbuild. A correction of the cause also corrects this condition.

Proposed correction

The activity of the build must be present when the build event arrives. Use one of these three methods:

  1. Stop the activity later. Move StopActivity from OnBuildFinished to Shutdown. MSBuild calls Shutdown after each telemetry event.
  2. Add the event to a known activity. Give the retained activity to TrackEventTask instead of Activity.Current.
  3. Send the build event before BuildFinished in MSBuild. This method needs a change in the MSBuild repository. The other two methods need a change only in this repository.

Method 1 is the smallest change. Confirm that Activity.Current is the correct activity in Shutdown. The measurement above gives evidence for this condition. The build event went to the parent of the stopped activity. Thus the async context of the telemetry event is the same context.

Part 2: Make the telemetry testable

No test finds the defect above. Three test methods exist today, and each one is successful when the defect is present.

FakeTelemetry (test/dotnet.Tests/CommandTests/MSBuild/FakeTelemetry.cs) shows that the logger called a method. It does not show that the process sent data.

The tests in PR #55582 examine the parent of the activity. They use a synthetic IEventSource. They do not start a build. They do not start a server. They also do not examine the sequence of BuildFinished and the build event, thus they did not find the defect that remains.

The disk log (DOTNET_CLI_TELEMETRY_LOG_PATH) uses AddInMemoryExporter(s_activities). The product uses AddOtlpExporter or AddAzureMonitorTraceExporter.

Item 2.1: A telemetry test harness

Do not write a collector. The Aspire dashboard receives OTLP and gives a query API. Thus this team owns fewer parts. I verified each step of this method with the commands in part 1.

Create test/dotnet.Tests/TelemetryTests/TelemetryCollectorFixture.cs. The class does these operations:

  1. It starts the Aspire dashboard as a child process. It uses --allow-anonymous, thus a test needs no API key.
  2. It selects a free port for the frontend and a free port for OTLP. Two tests in parallel then use different ports.
  3. It gives the OTLP endpoint address to the test.
  4. It reads GET /api/telemetry/spans and returns the spans and their events.
  5. It stops the dashboard at the end of the test class.

The response is OTLP JSON. System.Text.Json reads it. The events array of each span contains a name and an attributes array. This structure is the structure that the SDK sends. Thus a test examines the event name, each tag name, and the activity of each event. A decoder for the protobuf format is not necessary.

The test needs the activity of each event, because the defect in part 1 is a wrong activity. A harness that returns only a list of event names cannot find this defect.

Give the fixture this API:

IReadOnlyList<CollectedSpan> spans = await fixture.GetSpansAsync();
CollectedSpan msbuild = spans.Single(s => s.Name == "msbuild");
msbuild.Events.Should().Contain(e => e.Name == "dotnet/cli/msbuild/build");

Use the PersistentStorageTelemetryE2ETests.cs file as the example for the child process. Use SdkTest, TestAssetsManager, and DotnetCommand in the same manner.

These tests do not operate on a source-build leg. Thus the acquisition of the tool is acceptable. Exclude these tests from each leg that has no network access.

Item 2.2: Tests for each host

Create test/dotnet.Tests/TelemetryTests/TelemetryHostMatrixTests.cs.

Use a matrix of the hosts. A list of conditions becomes old. A matrix shows which host has no test.

Host Environment The test examines this
MSBuild server, cold start default settings, no server operates One dotnet/cli/msbuild/build event on the msbuild activity. InitialMSBuildServerState is cold.
MSBuild server, hot start default settings, second build The same conditions. InitialMSBuildServerState is hot. Not zero events. Not two events.
In process MSBUILDUSESERVER=0 One event on the msbuild activity. InitialMSBuildServerState is absent.
Fall back to in process a condition that stops the server One event. ServerFallbackReason has a value.
Opt out DOTNET_CLI_TELEMETRY_OPTOUT=1 Zero events.

In .NET 11 the server is the default. Thus a test that sets MSBUILDUSESERVER manually does not test the path that most customers use. Use the default settings for the first two rows.

Assert the activity of the event, and not only the presence of the event. The in-process row is successful today, but the event is on the wrong activity. An assertion on the activity finds this condition also.

Two conditions from the measurement

These two conditions are necessary. Without them a test gives a false result.

1. Run dotnet build-server shutdown before each trial. An MSBuild process of a previous trial stays in memory. This process keeps the environment of its own trial. Thus it sends the telemetry to the wrong address, or it sends nothing. My first trials gave a false result for this reason.

2. Examine a control event in the same trial. A build sends dotnet/cli/toplevelparser/command and dotnet/cli/command/finish from the CLI process. Assert that these events are present. This assertion separates two conditions:

  • The build did not operate, or the export did not operate. Then the control events are also absent.
  • The build operated and the export operated, but the product discarded the build event. Then the control events are present.

The second condition is the defect in part 1. Without the control, a test cannot show the difference.

Item 2.3: A contract file and a CI gate

This item tells the contributors to test their new events.

Today a contributor gets no signal. The documentation/project-docs/telemetry.md file says: "Ensure that all telemetry events and properties are accurately documented". This is a convention. No code makes this necessary.

Use the Verify.MSTest package. This repository already references it in test/dotnet.Tests/dotnet.Tests.csproj. The test/dotnet.Tests/CommandTests/Test/snapshots/MTPHelpSnapshotTests.VerifyMTPHelpOutput.verified.txt file is an example of a snapshot.

Create test/dotnet.Tests/TelemetryTests/TelemetryContractTests.cs and its snapshot file. The test uses the harness of item 2.1. The snapshot contains each activity, each event name, and each tag name in sequence:

activity: msbuild
  dotnet/cli/msbuild/build
    BuildCheckEnabled
    BuildEngineHost
    BuildSuccess
    BuildTarget
    InitialMSBuildServerState
    ProjectPath
    ServerEnableReason
    ServerFallbackReason
  dotnet/cli/msbuild/loggingConfiguration
    ConsoleLogger
    TerminalLogger

The test removes the values, because a value is not stable. Then Verify compares the result with the snapshot file.

The snapshot contains the activity of each event. Thus a change of the activity also causes a failure.

MSBuildLogger.cs declares 16 constants with the EventName suffix. Add a test that reads these constants with reflection and compares them with the contract file. This check finds an event that no test condition sends.

The conditions of failure

Each message must tell the contributor the next action:

Condition The message
The code declares an event. The contract file does not contain it. "The event dotnet/cli/foo is not in the contract file. Add a test condition that sends this event. Then accept the new snapshot."
The contract file contains an event. No test sends it. "No test sends the event dotnet/cli/foo. Add a test condition, or remove the event from the contract file."
A tag name or its letter case changed. "The tag BuildSuccess changed to buildSuccess. This change stops the queries in the backend. Confirm that this change is necessary."
An event moved to a different activity. "The event dotnet/cli/msbuild/build moved from the activity msbuild to the activity invocation. Confirm that this change is necessary."

The documentation

Add a section to documentation/project-docs/telemetry.md. Give this instruction to a contributor who adds an event:

  1. Add the event name as a constant.
  2. Add a test condition to TelemetryHostMatrixTests that sends the event.
  3. Run the tests. Accept the new snapshot file.
  4. Add the event to the table in this document.

Optional: Make the error visible in the code

The items above examine the known events and the known hosts. This item protects the hosts that we do not know today. The AOT CLI and dotnet watch are examples.

Change TrackEventTask. Do one of these two operations:

  • Write a diagnostic message when no current activity is present. Use Debug.Fail in the debug build.
  • Let TelemetryClient start its own activity when no current activity is present.

The second operation also corrects the defect in part 1 for each host.

Acceptance criteria

Part 1

  • The activity of the build is present when the build event arrives.
  • A build with the MSBuild server sends one dotnet/cli/msbuild/build event.
  • The build event is on the msbuild activity, and not on the parent activity.
  • The tags of the event contain InitialMSBuildServerState.

Part 2, item 2.1

  • TelemetryCollectorFixture starts the Aspire dashboard and stops it. It uses free ports.
  • It returns the spans, their events, and the tags of each event.
  • It adds no package reference to the product or to the test project.

Part 2, item 2.2

  • TelemetryHostMatrixTests contains each row of the table in item 2.2.
  • Each trial runs dotnet build-server shutdown first.
  • Each trial asserts a control event from the CLI process.
  • Each trial asserts the activity of the build event.
  • Remove the correction of part 1. Then the two server rows must fail. The other rows must stay successful. This criterion shows that the tests find the defect.

Part 2, item 2.3

  • The contract snapshot file exists. It contains the activities, the events, and their tags.
  • A new event without a contract entry causes a failure. The message gives the next action.
  • A changed tag name causes a failure.
  • An event on a different activity causes a failure.
  • telemetry.md contains the four steps for a contributor.

Related items

Notes

Do not remove TelemetryDiskLogger. It is useful for local diagnosis. But it must not be the only test of the real output.

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions