Skip to content

Improve dotnetup error handling#55155

Open
nagilson wants to merge 25 commits into
dotnet:release/dnupfrom
nagilson:nagilson-improve-error-collection
Open

Improve dotnetup error handling#55155
nagilson wants to merge 25 commits into
dotnet:release/dnupfrom
nagilson:nagilson-improve-error-collection

Conversation

@nagilson

@nagilson nagilson commented Jul 6, 2026

Copy link
Copy Markdown
Member

Background

#54733 since this PR was merged, we've seen a significant drop in failures; almost to the point where it looks like dotnetup is working perfectly 99.99% of the time.

That's definitely not true.
(Evidence: #55157, #55147, etc...)

Context

So, I embarked in a journey to understand why this could happen. In that journey, I cleaned up the telemetry code, inspected every single flag that we have, read some of the OTel implementation and Azure Logger implementation, and ran some experiments over the span of a week to see what made data come in and what prevented data from coming in.

The first result of that was an improvement to the POST time by using the correct connection string. #55126

The second included readability improvements to the dashboard.
#55156

This one includes fixes to the implementation itself.

The problem with OTel & Azure Monitor Exporter's OTel

The core result of this is that I believe the .NET implementation of OTel we use is designed first and foremost for a continuous service or desktop application and not a CLI/one-and-done program so we are going to need to change things a bit.

Evidence:

  1. Blob storage is only pushed after POST (of the telemetry data) fails. One and done / CLI applications are often not going to give enough time for that to happen, since it requires that they wait around, unless they fork which dotnet is really not meant for. This means the 'blob' store that backs up data in the event that it fails to send is effectively moot.

POST attempted, and only on failure is the blob saved:
https://github.com/Azure/azure-sdk-for-net/blob/Azure.Monitor.OpenTelemetry.Exporter_1.4.0/sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/src/Internals/AzureMonitorTransmitter.cs#L171-L182

The actual save calls (all inside failure handling): https://github.com/Azure/azure-sdk-for-net/blob/713fe00ec70a87a1db4bf836d029bd8ce3b83d03/sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/src/Internals/HttpPipelineHelper.cs#L183-L226

  1. Flush is not tied to delivery of POST finishing but whether the POST request has been dequeued from the queue of telemetry work to do.

https://github.com/Azure/azure-sdk-for-net/blob/Azure.Monitor.OpenTelemetry.Exporter_1.4.0/sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/src/AzureMonitorLogExporter.cs#L53

This waits on WaitForExport : https://github.com/open-telemetry/opentelemetry-dotnet/blob/core-1.15.3/src/OpenTelemetry/BatchExportProcessor.cs#L98-L101

WaitForExport just loops until it's dequeued. https://github.com/open-telemetry/opentelemetry-dotnet/blob/d622e6c7c899527638b53a6b06919859f5752add/src/OpenTelemetry/Internal/BatchExportThreadWorker.cs#L69-L72

  1. Blob storage only gets looked at to resend after 120s of waiting in the program - there is no control or way to trigger flushing the blob storage artifacts out manually; CLI apps are often not going to take 120s.

https://github.com/Azure/azure-sdk-for-net/blob/Azure.Monitor.OpenTelemetry.Exporter_1.4.0/sdk/monitor/Azure.Monitor.OpenTelemetry.Exporter/src/Internals/TransmitFromStorageHandler.cs#L31-L35

  1. There is low incrementality in the controllable duration to send more datum; 0-1000ms is the only direct control lever, then intervals are controlled by the second as the loop logic does min(user_timeout, 1000).

https://github.com/open-telemetry/opentelemetry-dotnet/blob/core-1.15.3/src/OpenTelemetry/Internal/BatchExportThreadWorker.cs#L95

  1. Flush / Dispose depend on the application process sticking around rather than being methods designed to hook into at the end of a program, considering all of the above.

https://github.com/open-telemetry/opentelemetry-dotnet/blob/d622e6c7c899527638b53a6b06919859f5752add/src/OpenTelemetry/BatchExportProcessor.cs#L104-L138

  1. It is impractical to idle wait at the end of a CLI application for long enough based on how long it actually takes to send data.

Unfortunately upon inspection, besides Geneva (that relies on an always on local agent) like implementations, other OTEL exporters have a similar problem.

Current Changes

  • Rerouted flush delay: increased it for baseline scenarios but for errors, we now always wait with a longer flush cycle to try to make sure they get through, as there is more thread contention for that exception handling vs telemetry APIs.
  • Modified flush delay based on interactive scenarios, but also made it "super fast" still for print-env-script as that's what hooks directly into the user's profile.
  • Disambiguated Flush (meant to dequeue POST requests) vs Dispose ( meant to shut down all listeners, but that happens automatically already on application shutdown ) as a pattern that is only used for concurrent tests teardown.
  • Cleaned up comments/various code in the Telemetry Client.
  • Unset options that had no relevance on whether the code worked or not (e.g. scopes)
  • Moved path finding logic into the unified place.
  • Reduced ? members to be required and defined to improve code clarity and assertiveness.
  • Ensured that error is always defined rather than only being defined if there was an error. (This was part of my investigation trying to figure out whether error tagging was a problem or not; it was not because no data that ever had an error seemed to ever have time to POST before the app exited with the 10ms change.)
  • Share the flush timer deadline so it's not actually 2x the flush timer timeout duration.

What's next

I suggest we implement our own blob storage and POST handler that runs out of process; rather than forking, it will spawn a detached separate process that will handle the POST and or storage contention. Alternatively, we can work with OTel/others on this.

nagilson added 19 commits June 30, 2026 14:46
…er be null

If it is null, id rather the program fail because that is not a good sign.
Production drains via Flush; Dispose now mirrors Aspire's non-blocking
Shutdown(0) so tests don't hang on the OTel LoggerProvider's unbounded
Dispose-time Shutdown(Timeout.Infinite).
Replace the 10ms/2000ms literals with DefaultFlushTimeoutMs=200 and
DurableFlushTimeoutMs=5000. 200ms is enough to hand the cold AppInsights
POST to the batch processor so it can spill to the offline store.
ForceFlush is synchronous/blocking; flushing each provider with the full
budget could cost up to 2x on a dead network. Logger (the data-x traces
signal) now flushes first with the full budget and the tracer gets only
the leftover, bounding total flush to ~1x the budget.
GetFlushTimeoutMs now takes the exit code. Precedence: explicit
DOTNETUP_TELEMETRY_FLUSH_TIMEOUT_MS override; failure -> durable; shell
startup (print-env-script) -> default even when redirected; interactive
foreground -> default; else (CI/piped/non-interactive) -> durable.
Flush takes the process exit code and derives the budget via
GetFlushTimeoutMs(exitCode). Add FlushWithTimeout(int) for tests/diagnostics.
Program.Main's finally now calls FlushTelemetry(processExitCode) and never
calls Dispose() (which would trigger the OTel unbounded shutdown drain).
Update the two telemetry flush tests to the new API.
DOTNETUP_TELEMETRY_SIMULATE_ERROR makes the next command throw a
deterministic exception mapped to an EXISTING classified error.type
(product: InvalidOperation/LocalManifestCorrupted/SignatureVerificationFailed;
user: PlatformNotSupported/PermissionDenied). Paired with the P6
DOTNETUP_TELEMETRY_FLUSH_TIMEOUT_MS knob to validate which flush budget x
environment combinations reach the dashboard. No new events => no GDPR
re-classification needed.
The ServiceProvider owns _loggerFactory and the OTel _loggerProvider
(both resolved from it) and disposes them transitively, so Dispose() now
only Shutdown(0)s both providers (non-blocking teardown) then calls
_services.Dispose(). The two transitively-owned fields carry a CA2213
suppression with justification instead of redundant explicit disposes.
56 telemetry/tracked-operation tests pass (0.38s, no hang).
One-emit-per-process xunit harness that attaches an EventListener to the
Azure Monitor exporter EventSource (OpenTelemetry-AzureMonitor-Exporter,
v1.4.0) and records per-emit TransmissionSuccess/FailedToTransmit/NO_SIGNAL
alongside the captured Activity TraceId (== dashboard OperationId). Enables
a 1:1 join of the in-process delivery verdict against the row that later
lands in RawEventsTraces, to validate (not assume) the listener. Gated
behind DOTNETUP_TELEMETRY_LISTENER_HARNESS=1 (no-op otherwise).
The docstring wrongly claimed RecordException emits a separate severity=Error
LogRecord; it does not — error metadata is folded into the single completion
row at dispose. Corrected the docs to describe the atomic-row behavior.

Defense-in-depth: wrap the classify/propagate/set-status body in a catch-all
so a throwing ErrorCodeMapper.GetErrorInfo (stack-trace string processing,
NativeAOT edge cases) can never escape the failure path and corrupt or drop
the completion row. On classification failure the row still emits with a
coarse error.type=TelemetryClassificationError (product) so the failure
signal is preserved.
@nagilson nagilson changed the title Nagilson improve error collection Improve dotnetup error handling Jul 6, 2026
@nagilson nagilson force-pushed the nagilson-improve-error-collection branch from d3f82be to 7fb9fb9 Compare July 6, 2026 22:15
Removes the two 'revert before merge' harnesses used to validate that
dotnetup telemetry reaches the dashboard:
- TelemetryValidationHarness (DOTNETUP_TELEMETRY_SIMULATE_ERROR) and its
  call in CommandBase.Execute plus the SimulateErrorEnvVar constant.
- TelemetryListenerHarness test (EventListener transmission-verdict).

No production behavior change; the harnesses were no-ops unless their
env vars were set. Real telemetry tests and EnsureErrorTypeTagged /
flush-budget features are retained.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Comment thread src/Installer/dotnetup.Library/CommandBase.cs Outdated
Comment thread src/Installer/dotnetup.Library/Constants.cs Outdated
Comment thread src/Installer/dotnetup.Library/Program.cs Outdated
Comment thread src/Installer/Microsoft.Dotnet.Installation/Internal/TrackedOperation.cs Outdated
nagilson added 2 commits July 6, 2026 16:34
- Remove duplicate EnsureErrorTypeTagged_WhenNoError_StampsEmptyString test (CS0111 build break); keep the copy that actually asserts error.type == empty string.

- Centralize error.type defaulting: call EnsureErrorTypeTagged() from SetStatus() (the single choke point every top-level op ends through) instead of each caller (Program root + CommandBase). Sub-events never call SetStatus, so scope is unchanged.

- Trim over-explaining comments/docstrings per review (CommandBase ctor, FlushTimeoutOverrideEnvVar, FlushTelemetry, EnsureErrorTypeTagged).
The kept EnsureErrorTypeTagged tests used xUnit-style Assert.Single/NotNull/Equal, which do not exist on MSTest's Assert (the previous CS0111 duplicate-method error masked these until it was fixed). Convert to the MSTest equivalents already used throughout the file: ContainsSingle, IsNotNull, AreEqual.
@nagilson nagilson marked this pull request as ready for review July 7, 2026 21:50
Copilot AI review requested due to automatic review settings July 7, 2026 21:50

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Pull request overview

This PR improves dotnetup telemetry reliability and error reporting for a CLI “one-and-done” execution model by (1) revising flush budgeting/behavior and (2) making error tagging more uniform and robust.

Changes:

  • Reworks telemetry flushing: budget is derived from exit code + environment, uses a shared deadline, and avoids Dispose() during normal process shutdown.
  • Ensures error.type is always present (empty string on success) by stamping it when operations set status, and updates tests accordingly.
  • Simplifies command telemetry wiring by passing a stable command name into CommandBase and starting the per-command tracked operation there; path/telemetry storage helpers are centralized in DotnetupPaths.

Reviewed changes

Copilot reviewed 22 out of 22 changed files in this pull request and generated 4 comments.

Show a summary per file
File Description
test/dotnetup.Tests/TelemetryTests.cs Updates flush/exception tests and adds coverage for EnsureErrorTypeTagged.
test/dotnetup.Tests/TelemetryE2ETests.cs Adjusts E2E assertions to match the new “error.type always stamped” behavior.
src/Installer/Microsoft.Dotnet.Installation/Internal/TrackedOperation.cs Ensures error.type is stamped (empty string) when status is set; adds EnsureErrorTypeTagged().
src/Installer/dotnetup.Library/Telemetry/DotnetupTelemetry.cs Refactors flush logic/budgeting, hardens RecordException, centralizes paths, and clarifies logger/tracer ownership/teardown.
src/Installer/dotnetup.Library/Program.cs Flushes telemetry on exit based on exit code and avoids Dispose() on normal shutdown.
src/Installer/dotnetup.Library/DotnetupPaths.cs Centralizes telemetry storage and disk-log path derivation.
src/Installer/dotnetup.Library/Constants.cs Adds DOTNETUP_TELEMETRY_FLUSH_TIMEOUT_MS override env var.
src/Installer/dotnetup.Library/Commands/Shared/InstallCommand.cs Updates base ctor usage to supply a stable telemetry command name.
src/Installer/dotnetup.Library/Commands/Sdk/Update/SdkUpdateCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Sdk/Uninstall/SdkUninstallCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Sdk/Install/SdkInstallCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Runtime/Update/RuntimeUpdateCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Runtime/Uninstall/RuntimeUninstallCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Runtime/Install/RuntimeInstallCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/PrintEnvScript/PrintEnvScriptCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/List/ListCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Init/InitCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Info/InfoCommand.cs Moves command name to base ctor; removes GetCommandName() override (including test ctor).
src/Installer/dotnetup.Library/Commands/ElevatedAdminPath/ElevatedAdminPathCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/Dotnet/DotnetCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/Commands/DefaultInstall/DefaultInstallCommand.cs Moves command name to base ctor; removes GetCommandName() override.
src/Installer/dotnetup.Library/CommandBase.cs Starts per-command tracked operation in ctor using the provided stable command name; removes GetCommandName() abstraction.

Comment thread src/Installer/dotnetup.Library/Telemetry/DotnetupTelemetry.cs
Comment thread src/Installer/dotnetup.Library/Telemetry/DotnetupTelemetry.cs
Comment thread test/dotnetup.Tests/TelemetryE2ETests.cs Outdated
Comment thread test/dotnetup.Tests/TelemetryTests.cs Outdated
nagilson added 2 commits July 7, 2026 15:20
this fixes a test that existed but did not really cover the code properly.
@nagilson nagilson requested review from a team and dsplaisted July 7, 2026 22:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants