Ignore invalid correlation context tokens in Http Diagnostics Listener (dotnet/corefx...

* Fix 31687: ignore invalid correlation context tokens

* add comments

* Add outerloop category

* url-encode correlation context keys and values

Commit migrated from https://github.com/dotnet/corefx/commit/fcbd6804cee9ededfb9db50d7540749640137952

diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandler.cs b/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandler.cs
index 8da9cf5..7876e99 100644 (file)
--- a/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandler.cs
+++ b/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandler.cs
@@ -36,7 +36,7 @@ namespace System.Net.Http
             //HttpClientHandler is responsible to call DiagnosticsHandler.IsEnabled() before forwarding request here.
             //This code will not be reached if no one listens to 'HttpHandlerDiagnosticListener', unless consumer unsubscribes
             //from DiagnosticListener right after the check. So some requests happening right after subscription starts
-            //might not be instrumented. Similarly, when consumer unsubscribes, extra requests might be instumented
+            //might not be instrumented. Similarly, when consumer unsubscribes, extra requests might be instrumented
 
             if (request == null)
             {
@@ -108,7 +108,7 @@ namespace System.Net.Http
                         do
                         {
                             KeyValuePair<string, string> item = e.Current;
-                            baggage.Add(new NameValueHeaderValue(item.Key, item.Value).ToString());
+                            baggage.Add(new NameValueHeaderValue(WebUtility.UrlEncode(item.Key), WebUtility.UrlEncode(item.Value)).ToString());
                         }
                         while (e.MoveNext());
                         request.Headers.Add(DiagnosticsHandlerLoggingStrings.CorrelationContextHeaderName, baggage);
@@ -132,7 +132,7 @@ namespace System.Net.Http
             {
                 if (s_diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ExceptionEventName))
                 {
-                    //If request was initialy instrumented, Activity.Current has all necessary context for logging
+                    //If request was initially instrumented, Activity.Current has all necessary context for logging
                     //Request is passed to provide some context if instrumentation was disabled and to avoid
                     //extensive Activity.Tags usage to tunnel request properties
                     s_diagnosticListener.Write(DiagnosticsHandlerLoggingStrings.ExceptionEventName, new { Exception = ex, Request = request });
@@ -147,7 +147,7 @@ namespace System.Net.Http
                     s_diagnosticListener.StopActivity(activity, new
                     {
                         Response = responseTask?.Status == TaskStatus.RanToCompletion ? responseTask.Result : null,
-                        //If request is failed or cancelled, there is no reponse, therefore no information about request;
+                        //If request is failed or cancelled, there is no response, therefore no information about request;
                         //pass the request in the payload, so consumers can have it in Stop for failed/canceled requests
                         //and not retain all requests in Start 
                         Request = request,

diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs
index 6ed143d..1a7e0ef 100644 (file)
--- a/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs
+++ b/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs
@@ -492,6 +492,66 @@ namespace System.Net.Http.Functional.Tests
 
         [OuterLoop("Uses external server")]
         [Fact]
+        public void SendAsync_ExpectedDiagnosticSourceActivityLogging_InvalidBaggage()
+        {
+            RemoteInvoke(useSocketsHttpHandlerString =>
+            {
+                bool activityStopLogged = false;
+                bool exceptionLogged = false;
+
+                Activity parentActivity = new Activity("parent");
+                parentActivity.AddBaggage("bad/key", "value");
+                parentActivity.AddBaggage("goodkey", "bad/value");
+                parentActivity.AddBaggage("key", "value");
+                parentActivity.Start();
+
+                var diagnosticListenerObserver = new FakeDiagnosticListenerObserver(kvp =>
+                {
+                    if (kvp.Key.Equals("System.Net.Http.HttpRequestOut.Stop"))
+                    {
+                        Assert.NotNull(kvp.Value);
+                        Assert.NotNull(Activity.Current);
+                        Assert.Equal(parentActivity, Activity.Current.Parent);
+                        Assert.True(Activity.Current.Duration != TimeSpan.Zero);
+                        var request = GetPropertyValueFromAnonymousTypeInstance<HttpRequestMessage>(kvp.Value, "Request");
+                        Assert.True(request.Headers.TryGetValues("Request-Id", out var requestId));
+                        Assert.True(request.Headers.TryGetValues("Correlation-Context", out var correlationContext));
+                        Assert.Equal(3, correlationContext.Count());
+                        Assert.True(correlationContext.Contains("key=value"));
+                        Assert.True(correlationContext.Contains("bad%2Fkey=value"));
+                        Assert.True(correlationContext.Contains("goodkey=bad%2Fvalue"));
+
+                        var requestStatus = GetPropertyValueFromAnonymousTypeInstance<TaskStatus>(kvp.Value, "RequestTaskStatus");
+                        Assert.Equal(TaskStatus.RanToCompletion, requestStatus);
+
+                        activityStopLogged = true;
+                    }
+                    else if (kvp.Key.Equals("System.Net.Http.Exception"))
+                    {
+                        exceptionLogged = true;
+                    }
+                });
+
+                using (DiagnosticListener.AllListeners.Subscribe(diagnosticListenerObserver))
+                {
+                    diagnosticListenerObserver.Enable(s => s.Contains("HttpRequestOut"));
+                    using (HttpClient client = CreateHttpClient(useSocketsHttpHandlerString))
+                    {
+                        client.GetAsync(Configuration.Http.RemoteEchoServer).Result.Dispose();
+                    }
+
+                    // Poll with a timeout since logging response is not synchronized with returning a response.
+                    WaitForTrue(() => activityStopLogged, TimeSpan.FromSeconds(1), "Response was not logged within 1 second timeout.");
+                    Assert.False(exceptionLogged, "Exception was logged for successful request");
+                    diagnosticListenerObserver.Disable();
+                }
+
+                return SuccessExitCode;
+            }, UseSocketsHttpHandler.ToString()).Dispose();
+        }
+
+        [OuterLoop("Uses external server")]
+        [Fact]
         public void SendAsync_ExpectedDiagnosticSourceActivityLoggingDoesNotOverwriteHeader()
         {
             RemoteInvoke(useSocketsHttpHandlerString =>