Skip to content
47 changes: 39 additions & 8 deletions csharp/src/RetryHttpHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
*/

using System;
using System.Collections.Generic;
using System.IO;
using System.Net;
using System.Net.Http;
Expand Down Expand Up @@ -142,10 +143,6 @@ protected override async Task<HttpResponseMessage> SendAsync(
attemptCount++;
lastTransportException = ex;

activity?.SetTag("http.retry.attempt", attemptCount);
activity?.SetTag("http.retry.transport_error", ex.GetType().Name);
activity?.SetTag("http.retry.transport_error_message", ex.Message);

int transportWaitSeconds = CalculateBackoffWithJitter(currentBackoffSeconds);
lastErrorMessage = $"Transport error ({ex.GetType().Name}: {ex.Message}). Using exponential backoff of {transportWaitSeconds} seconds. Attempt {attemptCount}.";

Expand All @@ -161,6 +158,19 @@ protected override async Task<HttpResponseMessage> SendAsync(
}
totalTransportErrorRetrySeconds += transportWaitSeconds;

// Issue #479: emit a per-retry event BEFORE we sleep so the

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🔵 Low — This replaces per-attempt span tags (http.retry.attempt, http.retry.transport_error, http.retry.transport_error_message, and the Retry-After path's top-level http.response.status_code) with retry.attempt events. That's the intended design (documented in the PR), and I confirmed no in-repo code or test reads the removed tags. Flagging only so a maintainer can confirm no external dashboard/log query depends on those top-level span tags — event attributes are queried differently than span tags in most backends, so any downstream consumer keyed on the old tags would silently go dark. No code change needed if none exist.

(Anchored to the nearest changed line — see the description for the exact location.)

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.

NEEDS HUMAN DECISION — the bots can't resolve this thread; a maintainer's input is required.

No code change warranted: the span-tag → event migration is the intended, PR-documented design. I re-verified via grep that no in-repo code or test reads the removed top-level span tags (http.retry.attempt, http.retry.transport_error, http.retry.transport_error_message, or the old top-level Retry-After http.response.status_code) — remaining references are the new retry.attempt event attributes and an unrelated CloudFetch DownloadFile span tag. The only open point is whether an external dashboard/log query depends on the old top-level tags, which cannot be determined from this repo and is exactly the maintainer confirmation the reviewer requested — needs human judgment on out-of-band observability consumers.

// trace makes the retry visible even if the process dies
// during the delay. The event is self-contained — it carries
// the per-retry detail that used to be written as overwritten
// span tags (attempt number, error type via reason, error message).
activity?.AddEvent("retry.attempt", new List<KeyValuePair<string, object?>>
{
new("http.retry.attempt_number", attemptCount),
new("http.retry.delay_ms", (long)transportWaitSeconds * 1000L),
new("http.retry.reason", $"transport_error_{ex.GetType().Name}"),
new("http.retry.error_message", ex.Message)
});

await Task.Delay(TimeSpan.FromSeconds(transportWaitSeconds), cancellationToken);
Comment on lines +165 to 174

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.

All 4 RetryTelemetry tests pass, including the transport-error event test with the new delay_ms assertion.

Pushed bc038a8 (bundled with 1 other thread(s)).

currentBackoffSeconds = Math.Min(currentBackoffSeconds * 2, _maxBackoffSeconds);
continue;
Expand All @@ -183,12 +193,14 @@ protected override async Task<HttpResponseMessage> SendAsync(
HttpStatusCode statusCode = response.StatusCode;
bool isTooManyRequests = statusCode == (HttpStatusCode)429;

// Log this retry attempt
activity?.SetTag("http.retry.attempt", attemptCount);
activity?.SetTag("http.response.status_code", (int)statusCode);

int waitSeconds;

// Issue #479: derive a reason string the retry.attempt
// event below will carry. We thread it alongside the
// existing lastErrorMessage so the event tag and the
// exception text stay consistent.
string retryReason;

// Check for Retry-After header
if (response.Headers.TryGetValues("Retry-After", out var retryAfterValues))
{
Expand All @@ -199,19 +211,22 @@ protected override async Task<HttpResponseMessage> SendAsync(
// Use the Retry-After value
waitSeconds = retryAfterSeconds;
lastErrorMessage = $"Service temporarily unavailable (HTTP {(int)statusCode}). Using server-specified retry after {waitSeconds} seconds. Attempt {attemptCount}.";
retryReason = $"retry_after_{(int)statusCode}";
}
else
{
// Invalid Retry-After value, use exponential backoff
waitSeconds = CalculateBackoffWithJitter(currentBackoffSeconds);
lastErrorMessage = $"Service temporarily unavailable (HTTP {(int)statusCode}). Invalid Retry-After header, using exponential backoff of {waitSeconds} seconds. Attempt {attemptCount}.";
retryReason = $"retry_after_{(int)statusCode}_invalid_header";
}
}
else
{
// No Retry-After header, use exponential backoff
waitSeconds = CalculateBackoffWithJitter(currentBackoffSeconds);
lastErrorMessage = $"Service temporarily unavailable (HTTP {(int)statusCode}). Using exponential backoff of {waitSeconds} seconds. Attempt {attemptCount}.";
retryReason = $"retry_after_{(int)statusCode}_no_header";
}

// Dispose the response before retrying
Expand Down Expand Up @@ -246,6 +261,22 @@ protected override async Task<HttpResponseMessage> SendAsync(
totalServiceUnavailableRetrySeconds += waitSeconds;
}

// Issue #479: emit a retry.attempt event BEFORE Task.Delay
// below. This lives on the SendAsync activity (created by
// TraceActivityAsync above) so a single completed activity
// carries all its retry attempts as ordered events. The event is
// self-contained — it carries the per-retry detail that used to be
// written as overwritten span tags (attempt number, status code).
// Attribute keys are namespaced to match the driver's telemetry
// vocabulary (http.retry.* / OTel http.response.status_code).
activity?.AddEvent("retry.attempt", new List<KeyValuePair<string, object?>>
{
new("http.retry.attempt_number", attemptCount),
new("http.retry.delay_ms", (long)waitSeconds * 1000L),
new("http.retry.reason", retryReason),
new("http.response.status_code", (int)statusCode)
});

// Wait for the calculated time
await Task.Delay(TimeSpan.FromSeconds(waitSeconds), cancellationToken);

Expand Down
141 changes: 141 additions & 0 deletions csharp/test/Unit/RetryHttpHandlerTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,10 @@
*/

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Net;
using System.Net.Http;
using System.Net.Sockets;
Expand Down Expand Up @@ -665,6 +668,144 @@ public async Task TransportError_PerRequestTimeoutIsRetried()
Assert.Equal(2, mockHandler.RequestCount); // 1 timeout + 1 success
}

// ---------------------------------------------------------------------
// Retry telemetry tests (issue #479)
//
// The RetryHttpHandler runs on every HTTP send and retries on
// Retry-After (503/429) responses and on transient transport errors —
// but historically it emitted zero per-attempt telemetry. A customer
// reading their own driver logs asking "did my failure retry then
// succeed, or did it fail without any retry?" could not answer from
// the trace alone.
//
// The fix (around the retry loop) is to emit a `retry.attempt` event
// for each *retry* (i.e. not the first try) on the wrapping SendAsync
// activity, carrying attempt_number/delay_ms/reason. The target
// consumer is the user reading local driver logs, so dashboard-shaped
// summary tags are intentionally not emitted.
//
// These tests capture the activity emitted by RetryHttpHandler via an
// ActivityListener attached to the MockActivityTracer's source name
// ("TestSource"), then assert on its Events.
// ---------------------------------------------------------------------

/// <summary>
/// Captures Activity objects emitted by an ActivitySource for in-test
/// assertions on tags and events.
/// </summary>
private sealed class ActivityCapture : IDisposable
{
private readonly ActivityListener _listener;
private readonly object _lock = new();
private readonly List<Activity> _stopped = new();

public ActivityCapture(string sourceName)
{
_listener = new ActivityListener
{
ShouldListenTo = source => source.Name == sourceName,
Sample = (ref ActivityCreationOptions<ActivityContext> _) => ActivitySamplingResult.AllDataAndRecorded,
ActivityStopped = activity =>
{
lock (_lock) { _stopped.Add(activity); }
}
};
ActivitySource.AddActivityListener(_listener);
}

public IReadOnlyList<Activity> StoppedActivities
{
get { lock (_lock) { return _stopped.ToArray(); } }
}

public void Dispose() => _listener.Dispose();
}

/// <summary>
/// Issue #479: when the first attempt succeeds, no `retry.attempt`
/// events fire.
/// </summary>
[Fact]
public async Task RetryTelemetry_NoRetry_EmitsNoEvents_Issue479()
{
using var capture = new ActivityCapture("TestSource");
var mockHandler = new MockHttpMessageHandler(new HttpResponseMessage(HttpStatusCode.OK));
var retryHandler = new RetryHttpHandler(mockHandler, new MockActivityTracer(), 5, 5, true, true);

await new HttpClient(retryHandler).GetAsync("http://test.com");

Activity sendAsync = capture.StoppedActivities.Single(a => a.OperationName == "SendAsync");
Assert.DoesNotContain(sendAsync.Events, e => e.Name == "retry.attempt");
}

/// <summary>
/// Issue #479: each retry triggered by a Retry-After response emits a
/// `retry.attempt` event with attempt_number / delay_ms / reason. The
/// reason string must reference the status code so 429 throttles are
/// distinguishable from 503s.
/// </summary>
[Theory]
[InlineData(HttpStatusCode.ServiceUnavailable, "503")]
[InlineData((HttpStatusCode)429, "429")]
public async Task RetryTelemetry_RetryAfter_EmitsAttemptEvents_Issue479(HttpStatusCode status, string expectedReasonSubstring)
{
using var capture = new ActivityCapture("TestSource");

var mockHandler = new MockHttpMessageHandler(new HttpResponseMessage(status)
{
Headers = { { "Retry-After", "1" } }
});
mockHandler.SetResponseAfterRetryCount(2, new HttpResponseMessage(HttpStatusCode.OK));

var retryHandler = new RetryHttpHandler(mockHandler, new MockActivityTracer(), 10, 10, true, true);
await new HttpClient(retryHandler).GetAsync("http://test.com");

Activity sendAsync = capture.StoppedActivities.Single(a => a.OperationName == "SendAsync");
var events = sendAsync.Events.Where(e => e.Name == "retry.attempt").ToList();
Assert.Equal(2, events.Count);

for (int i = 0; i < events.Count; i++)
{
var tags = events[i].Tags.ToDictionary(t => t.Key, t => t.Value);
Assert.Equal(i + 1, Convert.ToInt32(tags["http.retry.attempt_number"]));
Assert.True(Convert.ToInt64(tags["http.retry.delay_ms"]) >= 1000); // Retry-After: 1 → 1000ms
Assert.Contains(expectedReasonSubstring, (string)tags["http.retry.reason"]!);
Assert.Equal((int)status, Convert.ToInt32(tags["http.response.status_code"])); // OTel semantic-convention name
}
}

/// <summary>
/// Issue #479: a retry triggered by a transient transport error emits a
/// `retry.attempt` event carrying the per-retry detail that used to be written
/// as overwritten span tags — attempt_number, reason, and error_message.
/// </summary>
[Fact]
public async Task RetryTelemetry_TransportError_EmitsAttemptEventWithErrorDetail_Issue479()
{
using var capture = new ActivityCapture("TestSource");

var mockHandler = new MockHttpMessageHandler(new HttpResponseMessage(HttpStatusCode.OK));
// Throw a transient transport error for the first 2 attempts, then succeed.
mockHandler.SetExceptionForRequestCount(2, new HttpRequestException("Connection refused"));

var retryHandler = new RetryHttpHandler(mockHandler, new MockActivityTracer(), 10, 10, true, true,
transportErrorRetryEnabled: true, httpRequestTimeoutSeconds: 0);
await new HttpClient(retryHandler).GetAsync("http://test.com");

Activity sendAsync = capture.StoppedActivities.Single(a => a.OperationName == "SendAsync");
var events = sendAsync.Events.Where(e => e.Name == "retry.attempt").ToList();
Assert.Equal(2, events.Count); // 2 transport failures → 2 retry events

for (int i = 0; i < events.Count; i++)
{
var tags = events[i].Tags.ToDictionary(t => t.Key, t => t.Value);
Assert.Equal(i + 1, Convert.ToInt32(tags["http.retry.attempt_number"]));
Assert.True(Convert.ToInt64(tags["http.retry.delay_ms"]) >= 1000); // backoff is Math.Max(1, ...) seconds → ≥ 1000ms
Assert.StartsWith("transport_error_", (string)tags["http.retry.reason"]!);
Assert.Equal("Connection refused", (string)tags["http.retry.error_message"]!);
}
}

/// <summary>
/// Mock HttpMessageHandler for testing the RetryHttpHandler.
/// </summary>
Expand Down
Loading