HTTP retries and redirects instrumentation

src/OpenTelemetry.Api/Internal/SpanAttributeConstants.cs

@@ -23,6 +23,8 @@ internal static class SpanAttributeConstants
     {
         public const string StatusCodeKey = "otel.status_code";
         public const string StatusDescriptionKey = "otel.status_description";
+        public const string PreviousTryContextKey = "otel.previous_try_context";
+        public const string RetryCountKey = "http.retry_count";
         public const string DatabaseStatementTypeKey = "db.statement_type";
     }
 }

src/OpenTelemetry.Instrumentation.Http/HttpRequestMessageContextPropagation.cs

@@ -34,6 +34,7 @@ internal static class HttpRequestMessageContextPropagation
 
         internal static Action<HttpRequestMessage, string, string> HeaderValueSetter => (request, name, value) =>
         {
+            request.Headers.Remove(name);
             request.Headers.Add(name, value);
         };
     }

src/OpenTelemetry.Instrumentation.Http/Implementation/HttpHandlerDiagnosticListener.cs

@@ -35,6 +35,8 @@ internal sealed class HttpHandlerDiagnosticListener : ListenerHandler
         internal static readonly Version Version = AssemblyName.Version;
         internal static readonly ActivitySource ActivitySource = new ActivitySource(ActivitySourceName, Version.ToString());
 
+        private const string RestartedActivityKey = "dotnet.restarted_activity";
+
         private static readonly Regex CoreAppMajorVersionCheckRegex = new Regex("^\\.NETCoreApp,Version=v(\\d+)\\.", RegexOptions.Compiled | RegexOptions.IgnoreCase);
 
         private readonly PropertyFetcher<HttpRequestMessage> startRequestFetcher = new PropertyFetcher<HttpRequestMessage>("Request");
@@ -88,14 +90,32 @@ public override void OnStartActivity(Activity activity, object payload)
                 return;
             }
 
-            // TODO: Investigate why this check is needed.
-            if (Propagators.DefaultTextMapPropagator.Extract(default, request, HttpRequestMessageContextPropagation.HeaderValuesGetter) != default)
+            var context = Propagators.DefaultTextMapPropagator.Extract(default, request, HttpRequestMessageContextPropagation.HeaderValuesGetter);
+            if (context != default && request.Properties.TryGetValue(SpanAttributeConstants.PreviousTryContextKey, out var previousContext))
             {
-                // this request is already instrumented, we should back off
+                // Handling request retry or redirect.
+                var retryCount = 1;
+                if (request.Properties.TryGetValue(SpanAttributeConstants.RetryCountKey, out var previousRetryCount))
+                {
+                    retryCount = (int)previousRetryCount + 1;
+                }
+
+                // Suppressing activity started by HttpClient DiagnosticsHandler.
                 activity.IsAllDataRequested = false;
-                return;
+                activity.Stop();
+
+                activity = ActivitySource.StartActivity(activity.Kind, context.ActivityContext, links: new[] { new ActivityLink((ActivityContext)previousContext) });
+                Activity.Current = activity;
+
+                request.Properties[RestartedActivityKey] = activity;
+
+                activity.SetTag(SpanAttributeConstants.RetryCountKey, retryCount);
+                request.Properties[SpanAttributeConstants.RetryCountKey] = retryCount;
             }
 
+            // Store activity context for the next possible try.
+            request.Properties[SpanAttributeConstants.PreviousTryContextKey] = activity.Context;
+
             // Propagate context irrespective of sampling decision
             var textMapPropagator = Propagators.DefaultTextMapPropagator;
             if (!(this.httpClientSupportsW3C && textMapPropagator is TraceContextPropagator))
@@ -195,6 +215,15 @@ public override void OnStopActivity(Activity activity, object payload)
                         HttpInstrumentationEventSource.Log.EnrichmentException(ex);
                     }
                 }
+
+                if (this.startRequestFetcher.TryFetch(payload, out HttpRequestMessage request) && request != null)
+                {
+                    if (request.Properties.TryGetValue(RestartedActivityKey, out object restartedActivityInstance))
+                    {
+                        var restartedActivity = (Activity)restartedActivityInstance;
+                        restartedActivity.Stop();
+                    }
+                }
             }
         }
 

src/OpenTelemetry.Instrumentation.Http/Implementation/HttpWebRequestActivitySource.netfx.cs

@@ -22,6 +22,7 @@
 using System.Reflection;
 using System.Reflection.Emit;
 using System.Runtime.CompilerServices;
+using System.Threading;
 using OpenTelemetry.Context.Propagation;
 using OpenTelemetry.Trace;
 
@@ -40,7 +41,7 @@ internal static class HttpWebRequestActivitySource
         public const string ActivityName = ActivitySourceName + ".HttpRequestOut";
 
         internal static readonly Func<HttpWebRequest, string, IEnumerable<string>> HttpWebRequestHeaderValuesGetter = (request, name) => request.Headers.GetValues(name);
-        internal static readonly Action<HttpWebRequest, string, string> HttpWebRequestHeaderValuesSetter = (request, name, value) => request.Headers.Add(name, value);
+        internal static readonly Action<HttpWebRequest, string, string> HttpWebRequestHeaderValuesSetter = (request, name, value) => request.Headers.Set(name, value);
 
         internal static HttpWebRequestInstrumentationOptions Options = new HttpWebRequestInstrumentationOptions();
 
@@ -199,10 +200,6 @@ private static void AddExceptionTags(Exception exception, Activity activity)
         private static void InstrumentRequest(HttpWebRequest request, ActivityContext activityContext)
             => Propagators.DefaultTextMapPropagator.Inject(new PropagationContext(activityContext, Baggage.Current), request, HttpWebRequestHeaderValuesSetter);
 
-        [MethodImpl(MethodImplOptions.AggressiveInlining)]
-        private static bool IsRequestInstrumented(HttpWebRequest request)
-            => Propagators.DefaultTextMapPropagator.Extract(default, request, HttpWebRequestHeaderValuesGetter) != default;
-
         private static void ProcessRequest(HttpWebRequest request)
         {
             if (!WebRequestActivitySource.HasListeners() || !Options.EventFilter(request))
@@ -216,15 +213,40 @@ private static void ProcessRequest(HttpWebRequest request)
                 return;
             }
 
-            if (IsRequestInstrumented(request))
+            if (RequestProperties.Instance == null)
+            {
+                RequestProperties.Instance = new Dictionary<string, object>();
+            }
+
+            Activity activity;
+            var context = Propagators.DefaultTextMapPropagator.Extract(default, request, HttpWebRequestHeaderValuesGetter);
+            if (context != default && RequestProperties.Instance.TryGetValue(SpanAttributeConstants.PreviousTryContextKey, out var previousContext))
             {
                 // This request was instrumented by previous
-                // ProcessRequest, such is the case with redirect responses where the same request is sent again.
-                return;
+                // ProcessRequest, such is the case with retries or redirect responses where the same request is sent again.
+
+                var retryCount = 1;
+                if (RequestProperties.Instance.TryGetValue(SpanAttributeConstants.RetryCountKey, out var previousRetryCount))
+                {
+                    retryCount = (int)previousRetryCount + 1;
+                }
+
+                activity = WebRequestActivitySource.StartActivity(ActivityName, ActivityKind.Client, context.ActivityContext, links: new[] { new ActivityLink((ActivityContext)previousContext) });
+
+                activity?.SetTag(SpanAttributeConstants.RetryCountKey, retryCount);
+                RequestProperties.Instance[SpanAttributeConstants.RetryCountKey] = retryCount;
+            }
+            else
+            {
+                activity = WebRequestActivitySource.StartActivity(ActivityName, ActivityKind.Client);
             }
 
-            var activity = WebRequestActivitySource.StartActivity(ActivityName, ActivityKind.Client);
             var activityContext = Activity.Current?.Context ?? default;
+            if (activityContext != default)
+            {
+                // Store activity context for the next possible try.
+                RequestProperties.Instance[SpanAttributeConstants.PreviousTryContextKey] = activityContext;
+            }
 
             // Propagation must still be done in all cases, to allow
             // downstream services to continue from parent context, if any.
@@ -636,6 +658,17 @@ private static Func<object[], T> CreateTypeInstance<T>(ConstructorInfo construct
             return (Func<object[], T>)setterMethod.CreateDelegate(typeof(Func<object[], T>));
         }
 
+        private static class RequestProperties
+        {
+            private static readonly AsyncLocal<Dictionary<string, object>> Properties = new AsyncLocal<Dictionary<string, object>>();
+
+            public static Dictionary<string, object> Instance
+            {
+                get => Properties.Value;
+                set => Properties.Value = value;
+            }
+        }
+
         private class HashtableWrapper : Hashtable, IEnumerable
         {
             private readonly Hashtable table;

test/OpenTelemetry.Instrumentation.Http.Tests/HttpClientTests.Basic.netcore31.cs

@@ -272,9 +272,10 @@ public async Task HttpClientInstrumentation_AddViaFactory_HttpInstrumentation_Co
         }
 
         [Fact]
-        public async Task HttpClientInstrumentationBacksOffIfAlreadyInstrumented()
+        public async Task HttpClientInstrumentationWorksIfAlreadyInstrumented()
         {
-            // TODO: Investigate why this feature is required.
+            const string traceId = "0123456789abcdef0123456789abcdef";
+            const string parentSpanId = "0123456789abcdef";
             var processor = new Mock<BaseProcessor<Activity>>();
 
             var request = new HttpRequestMessage
@@ -283,7 +284,7 @@ public async Task HttpClientInstrumentationBacksOffIfAlreadyInstrumented()
                 Method = new HttpMethod("GET"),
             };
 
-            request.Headers.Add("traceparent", "00-0123456789abcdef0123456789abcdef-0123456789abcdef-01");
+            request.Headers.Add("traceparent", $"00-{traceId}-{parentSpanId}-01");
 
             using (Sdk.CreateTracerProviderBuilder()
                    .AddHttpClientInstrumentation()
@@ -294,7 +295,63 @@ public async Task HttpClientInstrumentationBacksOffIfAlreadyInstrumented()
                 await c.SendAsync(request);
             }
 
-            Assert.Equal(4, processor.Invocations.Count); // SetParentProvider/OnShutdown/Dispose/OnStart called.
+            Assert.Equal(5, processor.Invocations.Count); // SetParentProvider/OnStart/OnEnd/OnShutdown/Dispose called.
+            var activity = (Activity)processor.Invocations[2].Arguments[0];
+
+            Assert.Equal(ActivityKind.Client, activity.Kind);
+            Assert.NotEqual(default, activity.Context.SpanId);
+            Assert.NotEqual(traceId, activity.TraceId.ToString());
+            Assert.NotEqual(parentSpanId, activity.SpanId.ToString());
+            Assert.NotEqual(parentSpanId, activity.ParentSpanId.ToString());
+        }
+
+        /// <summary>
+        /// Test request connection retry: reflection hook does not throw.
+        /// </summary>
+        [Theory]
+        [InlineData("GET")]
+        [InlineData("POST")]
+        public async Task TestSecureTransportRetryFailureRequest(string method)
+        {
+            var processor = new Mock<BaseProcessor<Activity>>();
+
+            var uriBuilder = new UriBuilder(this.url) { Scheme = "https" };
+
+            using (Sdk.CreateTracerProviderBuilder()
+                       .AddHttpClientInstrumentation()
+                       .AddProcessor(processor.Object)
+                       .Build())
+            {
+                using (var client = new HttpClient(new SimpleRetryHandler(new HttpClientHandler(), maxRetryCount: 1)))
+                {
+                    var ex = await Assert.ThrowsAnyAsync<Exception>(() =>
+                    {
+                        return method == "GET"
+                            ? client.GetAsync(uriBuilder.Uri)
+                            : client.PostAsync(uriBuilder.Uri, new StringContent("hello world"));
+                    });
+                    Assert.True(ex is InvalidOperationException);
+                }
+            }
+
+            Assert.Equal(8, processor.Invocations.Count); // SetParentProvider/OnStart/OnEnd/OnStart/OnStart/OnEnd/OnShutdown/Dispose called.
+            var firstTry = (Activity)processor.Invocations[2].Arguments[0];
+            var secondTry = (Activity)processor.Invocations[5].Arguments[0];
+
+            Assert.Equal(ActivityKind.Client, firstTry.Kind);
+            Assert.NotEqual(default, firstTry.Context.SpanId);
+
+            Assert.Equal(ActivityKind.Client, secondTry.Kind);
+            Assert.NotEqual(default, secondTry.Context.SpanId);
+
+            ActivityLink activityLink = secondTry.Links.FirstOrDefault();
+            Assert.NotEqual(default, activityLink);
+            Assert.Equal(firstTry.Context.TraceId, activityLink.Context.TraceId);
+            Assert.Equal(firstTry.Context.SpanId, activityLink.Context.SpanId);
+
+            var retryCount = secondTry.GetTagItem("http.retry_count");
+            Assert.NotNull(retryCount);
+            Assert.Equal(1, (int)retryCount);
         }
 
         [Fact]
@@ -438,6 +495,39 @@ private static void ActivityEnrichment(Activity activity, string method, object
                     break;
             }
         }
+
+        private sealed class SimpleRetryHandler : DelegatingHandler
+        {
+            private readonly int maxRetryCount;
+
+            public SimpleRetryHandler(HttpMessageHandler innerHandler, int maxRetryCount = 3)
+                : base(innerHandler)
+            {
+                this.maxRetryCount = maxRetryCount;
+            }
+
+            protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
+            {
+                HttpResponseMessage response = null;
+                for (int i = 0; i < this.maxRetryCount + 1; i++)
+                {
+                    try
+                    {
+                        response = await base.SendAsync(request, cancellationToken);
+                        if (response.IsSuccessStatusCode)
+                        {
+                            return response;
+                        }
+                    }
+                    catch
+                    {
+                        // ignored
+                    }
+                }
+
+                return response;
+            }
+        }
     }
 }
 #endif