diff --git a/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs index ecff49e72016a8..11457e413800a2 100644 --- a/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/GenericLoopbackServer.cs @@ -11,6 +11,7 @@ using System.Net.Sockets; using System.Net.WebSockets; using System.Threading; +using System.Diagnostics; namespace System.Net.Test.Common { @@ -20,7 +21,7 @@ namespace System.Net.Test.Common public abstract class LoopbackServerFactory { public abstract GenericLoopbackServer CreateServer(GenericLoopbackOptions options = null); - public abstract Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null); + public abstract Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null); public abstract Task CreateConnectionAsync(SocketWrapper socket, Stream stream, GenericLoopbackOptions options = null); @@ -28,15 +29,52 @@ public abstract class LoopbackServerFactory // Common helper methods - public Task CreateClientAndServerAsync(Func clientFunc, Func serverFunc, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null) + public Task CreateClientAndServerAsync(Func clientFunc, Func serverFunc, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null) { - return CreateServerAsync(async (server, uri) => + times?.Add((100, s.ElapsedMilliseconds)); + var server = CreateServerAsync(async (server, uri) => { - Task clientTask = clientFunc(uri); - Task serverTask = serverFunc(server); + times?.Add((101, s.ElapsedMilliseconds)); + Task clientTask = Task.Run(async () => + { + times?.Add((300, s.ElapsedMilliseconds)); + try + { + times?.Add((301, s.ElapsedMilliseconds)); + await clientFunc(uri); + times?.Add((302, s.ElapsedMilliseconds)); + } + catch + { + times?.Add((303, s.ElapsedMilliseconds)); + throw; + } + times?.Add((304, s.ElapsedMilliseconds)); + }); + times?.Add((102, s.ElapsedMilliseconds)); + Task serverTask = Task.Run(async () => + { + times?.Add((400, s.ElapsedMilliseconds)); + try + { + times?.Add((401, s.ElapsedMilliseconds)); + await serverFunc(server); + times?.Add((402, s.ElapsedMilliseconds)); + } + catch + { + times?.Add((403, s.ElapsedMilliseconds)); + throw; + } + times?.Add((404, s.ElapsedMilliseconds)); + }); + times?.Add((103, s.ElapsedMilliseconds)); await new Task[] { clientTask, serverTask }.WhenAllOrAnyFailed().ConfigureAwait(false); - }, options: options).WaitAsync(TimeSpan.FromMilliseconds(millisecondsTimeout)); + times?.Add((104, s.ElapsedMilliseconds)); + }, options: options, times: times, s: s).WaitAsync(TimeSpan.FromMilliseconds(millisecondsTimeout)); + times?.Add((200, s.ElapsedMilliseconds)); + return server; } } diff --git a/src/libraries/Common/tests/System/Net/Http/Http2LoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/Http2LoopbackServer.cs index edbefefb6ac1f8..c76c12489f1f92 100644 --- a/src/libraries/Common/tests/System/Net/Http/Http2LoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/Http2LoopbackServer.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Net.Security; using System.Net.Sockets; @@ -222,12 +223,29 @@ private static Http2Options CreateOptions(GenericLoopbackOptions options) return http2Options; } - public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null) + public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null) { - using (var server = CreateServer(options)) + times?.Add((500, s.ElapsedMilliseconds)); + var server = CreateServer(options); + times?.Add((501, s.ElapsedMilliseconds)); + try { + times?.Add((502, s.ElapsedMilliseconds)); await funcAsync(server, server.Address).WaitAsync(TimeSpan.FromMilliseconds(millisecondsTimeout)); + times?.Add((503, s.ElapsedMilliseconds)); } + catch + { + times?.Add((504, s.ElapsedMilliseconds)); + throw; + } + finally + { + times?.Add((505, s.ElapsedMilliseconds)); + server.Dispose(); + times?.Add((506, s.ElapsedMilliseconds)); + } + times?.Add((507, s.ElapsedMilliseconds)); } public override Version Version => HttpVersion20.Value; diff --git a/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs index 6e511915f047b3..f3a8f7b482434c 100644 --- a/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs @@ -94,7 +94,7 @@ public override GenericLoopbackServer CreateServer(GenericLoopbackOptions option return new Http3LoopbackServer(_quicImplementationProvider, CreateOptions(options)); } - public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60000, GenericLoopbackOptions options = null) + public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null) { using GenericLoopbackServer server = CreateServer(options); await funcAsync(server, server.Address).WaitAsync(TimeSpan.FromMilliseconds(millisecondsTimeout)); diff --git a/src/libraries/Common/tests/System/Net/Http/HttpAgnosticLoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/HttpAgnosticLoopbackServer.cs index 88a8071153e6c0..37b9cbf8af2345 100644 --- a/src/libraries/Common/tests/System/Net/Http/HttpAgnosticLoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/HttpAgnosticLoopbackServer.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Net.Security; using System.Net.Sockets; @@ -206,7 +207,7 @@ private static HttpAgnosticOptions CreateOptions(GenericLoopbackOptions options) return httpOptions; } - public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null) + public override async Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null) { using (var server = CreateServer(options)) { diff --git a/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Authentication.cs b/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Authentication.cs index f7ccc3127e9abc..fafd78717ded7a 100644 --- a/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Authentication.cs +++ b/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Authentication.cs @@ -1,7 +1,9 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. +using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Net.Sockets; using System.Net.Test.Common; @@ -153,9 +155,82 @@ public async Task HttpClientHandler_MultipleAuthenticateHeaders_Succeeds(string var options = new LoopbackServer.Options { Domain = Domain, Username = Username, Password = Password }; await LoopbackServer.CreateServerAsync(async (server, url) => { - HttpClientHandler handler = CreateHttpClientHandler(); - Task serverTask = server.AcceptConnectionPerformAuthenticationAndCloseAsync(authenticateHeader); - await TestHelper.WhenAllCompletedOrAnyFailed(CreateAndValidateRequest(handler, url, HttpStatusCode.OK, s_credentials), serverTask); + Stopwatch s = Stopwatch.StartNew(); + ConcurrentQueue<(string, long)> list = new ConcurrentQueue<(string, long)>(); + try + { + HttpClientHandler handler = CreateHttpClientHandler(); + + Task serverTask = Task.Run(async () => + { + list.Enqueue(("ServerStart", s.ElapsedMilliseconds)); + try + { + await server.AcceptConnectionPerformAuthenticationAndCloseAsync(authenticateHeader); + list.Enqueue(("ServerStop", s.ElapsedMilliseconds)); + } + catch + { + list.Enqueue(("ServerException", s.ElapsedMilliseconds)); + throw; + } + finally + { + list.Enqueue(("ServerExit", s.ElapsedMilliseconds)); + } + }); + + Task clientTask = Task.Run(async () => + { + list.Enqueue(("ClientStart", s.ElapsedMilliseconds)); + try + { + handler.Credentials = s_credentials; + + HttpClient client = CreateHttpClient(handler); + list.Enqueue(("CreateHttpClient", s.ElapsedMilliseconds)); + try + { + list.Enqueue(("BeforeGetAsync", s.ElapsedMilliseconds)); + HttpResponseMessage response = await client.GetAsync(url); + list.Enqueue(("AfterGetAsync", s.ElapsedMilliseconds)); + try + { + Assert.Equal(HttpStatusCode.OK, response.StatusCode); + } + finally + { + list.Enqueue(("GetAsyncFinally1", s.ElapsedMilliseconds)); + response.Dispose(); + list.Enqueue(("GetAsyncFinally2", s.ElapsedMilliseconds)); + } + } + finally + { + list.Enqueue(("CreateHttpClientFinally1", s.ElapsedMilliseconds)); + client.Dispose(); + list.Enqueue(("CreateHttpClientFinally2", s.ElapsedMilliseconds)); + } + + list.Enqueue(("ClientStop", s.ElapsedMilliseconds)); + } + catch + { + list.Enqueue(("ClientException", s.ElapsedMilliseconds)); + throw; + } + finally + { + list.Enqueue(("ClientExit", s.ElapsedMilliseconds)); + } + }); + + await TestHelper.WhenAllCompletedOrAnyFailed(clientTask, serverTask); + } + catch (Exception ex) + { + throw new Exception(string.Join('\n', list.Select(l => $"{l.Item1,20} {l.Item2}")), ex); + } }, options); } diff --git a/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Cookies.cs b/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Cookies.cs index dbb1382c9aaf58..ab0b0a406eda4d 100644 --- a/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Cookies.cs +++ b/src/libraries/Common/tests/System/Net/Http/HttpClientHandlerTest.Cookies.cs @@ -151,34 +151,72 @@ await LoopbackServerFactory.CreateClientAndServerAsync( [Fact] public async Task GetAsync_AddMultipleCookieHeaders_CookiesSent() { - await LoopbackServerFactory.CreateClientAndServerAsync( - async uri => - { - using (HttpClient client = CreateHttpClient()) + List<(int, long)> times = new List<(int, long)>(); + Stopwatch s = Stopwatch.StartNew(); + + try + { + times.Add((0, s.ElapsedMilliseconds)); + + await LoopbackServerFactory.CreateClientAndServerAsync( + async uri => { - var requestMessage = new HttpRequestMessage(HttpMethod.Get, uri) { Version = UseVersion }; - requestMessage.Headers.Add("Cookie", "A=1"); - requestMessage.Headers.Add("Cookie", "B=2"); - requestMessage.Headers.Add("Cookie", "C=3"); + times.Add((10, s.ElapsedMilliseconds)); + HttpClient client = CreateHttpClient(); + times.Add((11, s.ElapsedMilliseconds)); + try + { + var requestMessage = new HttpRequestMessage(HttpMethod.Get, uri) { Version = UseVersion }; + requestMessage.Headers.Add("Cookie", "A=1"); + requestMessage.Headers.Add("Cookie", "B=2"); + requestMessage.Headers.Add("Cookie", "C=3"); + times.Add((12, s.ElapsedMilliseconds)); - await client.SendAsync(TestAsync, requestMessage); - } - }, - async server => - { - HttpRequestData requestData = await server.HandleRequestAsync(); + await client.SendAsync(TestAsync, requestMessage) + .WaitAsync(TimeSpan.FromSeconds(10)); + + times.Add((13, s.ElapsedMilliseconds)); + } + catch + { + times.Add((14, s.ElapsedMilliseconds)); + throw; + } + finally + { + times.Add((15, s.ElapsedMilliseconds)); + client.Dispose(); + } + }, + async server => + { + times.Add((20, s.ElapsedMilliseconds)); + + HttpRequestData requestData = await server.HandleRequestAsync() + .WaitAsync(TimeSpan.FromSeconds(15)); + + times.Add((21, s.ElapsedMilliseconds)); // Multiple Cookie header values are treated as any other header values and are // concatenated using ", " as the separator. string cookieHeaderValue = requestData.GetSingleHeaderValue("Cookie"); - var cookieValues = cookieHeaderValue.Split(new string[] { ", " }, StringSplitOptions.None); - Assert.Contains("A=1", cookieValues); - Assert.Contains("B=2", cookieValues); - Assert.Contains("C=3", cookieValues); - Assert.Equal(3, cookieValues.Count()); - }); + var cookieValues = cookieHeaderValue.Split(new string[] { ", " }, StringSplitOptions.None); + Assert.Contains("A=1", cookieValues); + Assert.Contains("B=2", cookieValues); + Assert.Contains("C=3", cookieValues); + Assert.Equal(3, cookieValues.Count()); + + times.Add((22, s.ElapsedMilliseconds)); + }, + millisecondsTimeout: 300_000); + } + catch (Exception ex) + { + times.Add((1, s.ElapsedMilliseconds)); + throw new Exception(string.Join('\n', times.Select(t => $"{t.Item1,2} {t.Item2}")), ex); + } } private string GetCookieValue(HttpRequestData request) diff --git a/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs index 7594b4908010fc..ae3a65e02b1a5d 100644 --- a/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/LoopbackServer.cs @@ -13,6 +13,7 @@ using System.Threading.Tasks; using System.Net.WebSockets; using Xunit; +using System.Diagnostics; namespace System.Net.Test.Common { @@ -1086,7 +1087,7 @@ public override GenericLoopbackServer CreateServer(GenericLoopbackOptions option return loopbackServer; } - public override Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null) + public override Task CreateServerAsync(Func funcAsync, int millisecondsTimeout = 60_000, GenericLoopbackOptions options = null, List<(int, long)> times = null, Stopwatch s = null) { return LoopbackServer.CreateServerAsync((server, uri) => funcAsync(server, uri), options: CreateOptions(options)); } diff --git a/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs b/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs index 2efde1fef9ad58..e37e6f636ed63e 100644 --- a/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs +++ b/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs @@ -60,7 +60,7 @@ public static async Task WhenAllOrAnyFailed(this Task[] tasks) // in the error we throw. try { - await Task.WhenAll(tasks).WaitAsync(TimeSpan.FromSeconds(3)); // arbitrary delay; can be dialed up or down in the future + await Task.WhenAll(tasks).WaitAsync(TimeSpan.FromSeconds(20)); // arbitrary delay; can be dialed up or down in the future } catch { } diff --git a/src/libraries/System.Net.Http/src/ILLink/ILLink.Substitutions.xml b/src/libraries/System.Net.Http/src/ILLink/ILLink.Substitutions.xml index 314469c96d7775..d6aea3dbf37e46 100644 --- a/src/libraries/System.Net.Http/src/ILLink/ILLink.Substitutions.xml +++ b/src/libraries/System.Net.Http/src/ILLink/ILLink.Substitutions.xml @@ -1,7 +1,7 @@ - + diff --git a/src/libraries/System.Net.Http/src/System.Net.Http.csproj b/src/libraries/System.Net.Http/src/System.Net.Http.csproj index 613416b90aa782..de569a89ee98b7 100644 --- a/src/libraries/System.Net.Http/src/System.Net.Http.csproj +++ b/src/libraries/System.Net.Http/src/System.Net.Http.csproj @@ -496,7 +496,6 @@ - internal sealed class DiagnosticsHandler : DelegatingHandler { - private static readonly DiagnosticListener s_diagnosticListener = - new DiagnosticListener(DiagnosticsHandlerLoggingStrings.DiagnosticListenerName); - - /// - /// DiagnosticHandler constructor - /// - /// Inner handler: Windows or Unix implementation of HttpMessageHandler. - /// Note that DiagnosticHandler is the latest in the pipeline - public DiagnosticsHandler(HttpMessageHandler innerHandler) : base(innerHandler) - { - } - - internal static bool IsEnabled() - { - // check if there is a parent Activity (and propagation is not suppressed) - // or if someone listens to HttpHandlerDiagnosticListener - return IsGloballyEnabled && (Activity.Current != null || s_diagnosticListener.IsEnabled()); - } + private const string Namespace = "System.Net.Http"; + private const string RequestWriteNameDeprecated = Namespace + ".Request"; + private const string ResponseWriteNameDeprecated = Namespace + ".Response"; + private const string ExceptionEventName = Namespace + ".Exception"; + private const string ActivityName = Namespace + ".HttpRequestOut"; + private const string ActivityStartName = ActivityName + ".Start"; + private const string ActivityStopName = ActivityName + ".Stop"; - internal static bool IsGloballyEnabled => GlobalHttpSettings.DiagnosticsHandler.EnableActivityPropagation; + private static readonly DiagnosticListener s_diagnosticListener = new("HttpHandlerDiagnosticListener"); + private static readonly ActivitySource s_activitySource = new(Namespace); - // SendAsyncCore returns already completed ValueTask for when async: false is passed. - // Internally, it calls the synchronous Send method of the base class. - protected internal override HttpResponseMessage Send(HttpRequestMessage request, CancellationToken cancellationToken) => - SendAsyncCore(request, async: false, cancellationToken).AsTask().GetAwaiter().GetResult(); + public static bool IsGloballyEnabled => GlobalHttpSettings.DiagnosticsHandler.EnableActivityPropagation; - protected internal override Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) => - SendAsyncCore(request, async: true, cancellationToken).AsTask(); - - private async ValueTask SendAsyncCore(HttpRequestMessage request, bool async, - CancellationToken cancellationToken) + public DiagnosticsHandler(HttpMessageHandler innerHandler) : base(innerHandler) { - // HttpClientHandler is responsible to call static DiagnosticsHandler.IsEnabled() before forwarding request here. - // It will check if propagation is on (because parent Activity exists or there is a listener) or off (forcibly disabled) - // This code won't be called 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 instrumented + Debug.Assert(IsGloballyEnabled); + } - if (request == null) + private static bool ShouldLogDiagnostics(HttpRequestMessage request, out Activity? activity) + { + if (request is null) { throw new ArgumentNullException(nameof(request), SR.net_http_handler_norequest); } - Activity? activity = null; - DiagnosticListener diagnosticListener = s_diagnosticListener; + activity = null; + + if (s_activitySource.HasListeners()) + { + activity = s_activitySource.CreateActivity(ActivityName, ActivityKind.Client); + } - // if there is no listener, but propagation is enabled (with previous IsEnabled() check) - // do not write any events just start/stop Activity and propagate Ids - if (!diagnosticListener.IsEnabled()) + if (activity is null) { - activity = new Activity(DiagnosticsHandlerLoggingStrings.ActivityName); - activity.Start(); - InjectHeaders(activity, request); + bool diagnosticListenerEnabled = s_diagnosticListener.IsEnabled(); - try + if (Activity.Current is not null || (diagnosticListenerEnabled && s_diagnosticListener.IsEnabled(ActivityName, request))) { - return async ? - await base.SendAsync(request, cancellationToken).ConfigureAwait(false) : - base.Send(request, cancellationToken); + // If a diagnostics listener is enabled for the Activity, always create one + activity = new Activity(ActivityName); } - finally + else { - activity.Stop(); + // There is no Activity, but we may still want to use the instrumented SendAsyncCore if diagnostic listeners are interested in other events + return diagnosticListenerEnabled; } } - Guid loggingRequestId = Guid.Empty; + activity.Start(); - // There is a listener. Check if listener wants to be notified about HttpClient Activities - if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityName, request)) + if (s_diagnosticListener.IsEnabled(ActivityStartName)) { - activity = new Activity(DiagnosticsHandlerLoggingStrings.ActivityName); + Write(ActivityStartName, new ActivityStartData(request)); + } - // Only send start event to users who subscribed for it, but start activity anyway - if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityStartName)) - { - StartActivity(diagnosticListener, activity, new ActivityStartData(request)); - } - else - { - activity.Start(); - } + InjectHeaders(activity, request); + + return true; + } + + protected internal override HttpResponseMessage Send(HttpRequestMessage request, CancellationToken cancellationToken) + { + if (ShouldLogDiagnostics(request, out Activity? activity)) + { + ValueTask sendTask = SendAsyncCore(request, activity, async: false, cancellationToken); + return sendTask.IsCompleted ? + sendTask.Result : + sendTask.AsTask().GetAwaiter().GetResult(); } - // try to write System.Net.Http.Request event (deprecated) - if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.RequestWriteNameDeprecated)) + else { - long timestamp = Stopwatch.GetTimestamp(); - loggingRequestId = Guid.NewGuid(); - Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.RequestWriteNameDeprecated, - new RequestData(request, loggingRequestId, timestamp)); + return base.Send(request, cancellationToken); + } + } + + protected internal override Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) + { + if (ShouldLogDiagnostics(request, out Activity? activity)) + { + return SendAsyncCore(request, activity, async: true, cancellationToken).AsTask(); + } + else + { + return base.SendAsync(request, cancellationToken); } + } + + private async ValueTask SendAsyncCore(HttpRequestMessage request, Activity? activity, bool async, CancellationToken cancellationToken) + { + Guid loggingRequestId = default; - // If we are on at all, we propagate current activity information - Activity? currentActivity = Activity.Current; - if (currentActivity != null) + if (s_diagnosticListener.IsEnabled(RequestWriteNameDeprecated)) { - InjectHeaders(currentActivity, request); + loggingRequestId = Guid.NewGuid(); + Write(RequestWriteNameDeprecated, new RequestData(request, loggingRequestId, Stopwatch.GetTimestamp())); } HttpResponseMessage? response = null; @@ -126,52 +124,39 @@ await base.SendAsync(request, cancellationToken).ConfigureAwait(false) : catch (OperationCanceledException) { taskStatus = TaskStatus.Canceled; - - // we'll report task status in HttpRequestOut.Stop throw; } catch (Exception ex) { - taskStatus = TaskStatus.Faulted; - - if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ExceptionEventName)) + if (s_diagnosticListener.IsEnabled(ExceptionEventName)) { - // 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 - Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.ExceptionEventName, new ExceptionData(ex, request)); + Write(ExceptionEventName, new ExceptionData(ex, request)); } + + taskStatus = TaskStatus.Faulted; throw; } finally { - // always stop activity if it was started - if (activity != null) + if (activity is not null) { - StopActivity(diagnosticListener, activity, new ActivityStopData( - response, - // 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, - taskStatus)); + activity.SetEndTime(DateTime.UtcNow); + + if (s_diagnosticListener.IsEnabled(ActivityStopName)) + { + Write(ActivityStopName, new ActivityStopData(response, request, taskStatus)); + } + + activity.Stop(); } - // Try to write System.Net.Http.Response event (deprecated) - if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ResponseWriteNameDeprecated)) + + if (s_diagnosticListener.IsEnabled(ResponseWriteNameDeprecated)) { - long timestamp = Stopwatch.GetTimestamp(); - Write(diagnosticListener, DiagnosticsHandlerLoggingStrings.ResponseWriteNameDeprecated, - new ResponseData( - response, - loggingRequestId, - timestamp, - taskStatus)); + Write(ResponseWriteNameDeprecated, new ResponseData(response, loggingRequestId, Stopwatch.GetTimestamp(), taskStatus)); } } } - #region private - private sealed class ActivityStartData { // matches the properties selected in https://github.com/dotnet/diagnostics/blob/ffd0254da3bcc47847b1183fa5453c0877020abd/src/Microsoft.Diagnostics.Monitoring.EventPipe/Configuration/HttpRequestSourceConfiguration.cs#L36-L40 @@ -271,22 +256,27 @@ internal ResponseData(HttpResponseMessage? response, Guid loggingRequestId, long private static void InjectHeaders(Activity currentActivity, HttpRequestMessage request) { + const string TraceParentHeaderName = "traceparent"; + const string TraceStateHeaderName = "tracestate"; + const string RequestIdHeaderName = "Request-Id"; + const string CorrelationContextHeaderName = "Correlation-Context"; + if (currentActivity.IdFormat == ActivityIdFormat.W3C) { - if (!request.Headers.Contains(DiagnosticsHandlerLoggingStrings.TraceParentHeaderName)) + if (!request.Headers.Contains(TraceParentHeaderName)) { - request.Headers.TryAddWithoutValidation(DiagnosticsHandlerLoggingStrings.TraceParentHeaderName, currentActivity.Id); + request.Headers.TryAddWithoutValidation(TraceParentHeaderName, currentActivity.Id); if (currentActivity.TraceStateString != null) { - request.Headers.TryAddWithoutValidation(DiagnosticsHandlerLoggingStrings.TraceStateHeaderName, currentActivity.TraceStateString); + request.Headers.TryAddWithoutValidation(TraceStateHeaderName, currentActivity.TraceStateString); } } } else { - if (!request.Headers.Contains(DiagnosticsHandlerLoggingStrings.RequestIdHeaderName)) + if (!request.Headers.Contains(RequestIdHeaderName)) { - request.Headers.TryAddWithoutValidation(DiagnosticsHandlerLoggingStrings.RequestIdHeaderName, currentActivity.Id); + request.Headers.TryAddWithoutValidation(RequestIdHeaderName, currentActivity.Id); } } @@ -302,41 +292,16 @@ private static void InjectHeaders(Activity currentActivity, HttpRequestMessage r baggage.Add(new NameValueHeaderValue(WebUtility.UrlEncode(item.Key), WebUtility.UrlEncode(item.Value)).ToString()); } while (e.MoveNext()); - request.Headers.TryAddWithoutValidation(DiagnosticsHandlerLoggingStrings.CorrelationContextHeaderName, baggage); + request.Headers.TryAddWithoutValidation(CorrelationContextHeaderName, baggage); } } } [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:UnrecognizedReflectionPattern", Justification = "The values being passed into Write have the commonly used properties being preserved with DynamicDependency.")] - private static void Write<[DynamicallyAccessedMembers(DynamicallyAccessedMemberTypes.PublicProperties)] T>( - DiagnosticSource diagnosticSource, - string name, - T value) + private static void Write<[DynamicallyAccessedMembers(DynamicallyAccessedMemberTypes.PublicProperties)] T>(string name, T value) { - diagnosticSource.Write(name, value); + s_diagnosticListener.Write(name, value); } - - [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:UnrecognizedReflectionPattern", - Justification = "The args being passed into StartActivity have the commonly used properties being preserved with DynamicDependency.")] - private static Activity StartActivity<[DynamicallyAccessedMembers(DynamicallyAccessedMemberTypes.PublicProperties)] T>( - DiagnosticSource diagnosticSource, - Activity activity, - T? args) - { - return diagnosticSource.StartActivity(activity, args); - } - - [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:UnrecognizedReflectionPattern", - Justification = "The args being passed into StopActivity have the commonly used properties being preserved with DynamicDependency.")] - private static void StopActivity<[DynamicallyAccessedMembers(DynamicallyAccessedMemberTypes.PublicProperties)] T>( - DiagnosticSource diagnosticSource, - Activity activity, - T? args) - { - diagnosticSource.StopActivity(activity, args); - } - - #endregion } } diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandlerLoggingStrings.cs b/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandlerLoggingStrings.cs deleted file mode 100644 index 0fa57394c1cc32..00000000000000 --- a/src/libraries/System.Net.Http/src/System/Net/Http/DiagnosticsHandlerLoggingStrings.cs +++ /dev/null @@ -1,25 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. - -namespace System.Net.Http -{ - /// - /// Defines names of DiagnosticListener and Write events for DiagnosticHandler - /// - internal static class DiagnosticsHandlerLoggingStrings - { - public const string DiagnosticListenerName = "HttpHandlerDiagnosticListener"; - public const string RequestWriteNameDeprecated = "System.Net.Http.Request"; - public const string ResponseWriteNameDeprecated = "System.Net.Http.Response"; - - public const string ExceptionEventName = "System.Net.Http.Exception"; - public const string ActivityName = "System.Net.Http.HttpRequestOut"; - public const string ActivityStartName = "System.Net.Http.HttpRequestOut.Start"; - - public const string RequestIdHeaderName = "Request-Id"; - public const string CorrelationContextHeaderName = "Correlation-Context"; - - public const string TraceParentHeaderName = "traceparent"; - public const string TraceStateHeaderName = "tracestate"; - } -} diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpClientHandler.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpClientHandler.cs index 89cb508d220e40..bfb8f6cae78348 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpClientHandler.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpClientHandler.cs @@ -20,17 +20,17 @@ namespace System.Net.Http public partial class HttpClientHandler : HttpMessageHandler { private readonly HttpHandlerType _underlyingHandler; - private readonly DiagnosticsHandler? _diagnosticsHandler; + private readonly HttpMessageHandler _handler; private ClientCertificateOption _clientCertificateOptions; private volatile bool _disposed; public HttpClientHandler() { - _underlyingHandler = new HttpHandlerType(); + _handler = _underlyingHandler = new HttpHandlerType(); if (DiagnosticsHandler.IsGloballyEnabled) { - _diagnosticsHandler = new DiagnosticsHandler(_underlyingHandler); + _handler = new DiagnosticsHandler(_handler); } ClientCertificateOptions = ClientCertificateOption.Manual; } @@ -288,21 +288,11 @@ public SslProtocols SslProtocols public IDictionary Properties => _underlyingHandler.Properties; [UnsupportedOSPlatform("browser")] - protected internal override HttpResponseMessage Send(HttpRequestMessage request, - CancellationToken cancellationToken) - { - return DiagnosticsHandler.IsEnabled() && _diagnosticsHandler != null ? - _diagnosticsHandler.Send(request, cancellationToken) : - _underlyingHandler.Send(request, cancellationToken); - } + protected internal override HttpResponseMessage Send(HttpRequestMessage request, CancellationToken cancellationToken) => + _handler.Send(request, cancellationToken); - protected internal override Task SendAsync(HttpRequestMessage request, - CancellationToken cancellationToken) - { - return DiagnosticsHandler.IsEnabled() && _diagnosticsHandler != null ? - _diagnosticsHandler.SendAsync(request, cancellationToken) : - _underlyingHandler.SendAsync(request, cancellationToken); - } + protected internal override Task SendAsync(HttpRequestMessage request, CancellationToken cancellationToken) => + _handler.SendAsync(request, cancellationToken); // lazy-load the validator func so it can be trimmed by the ILLinker if it isn't used. private static Func? s_dangerousAcceptAnyServerCertificateValidator; diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs index 1fb6fd925fd33c..66b60e800b8a77 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/DiagnosticsTests.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.Diagnostics; using System.Diagnostics.Tracing; +using System.IO; using System.Linq; using System.Net.Http.Headers; using System.Net.Test.Common; @@ -256,7 +257,7 @@ public void SendAsync_ExpectedDiagnosticCancelledLogging() GetProperty(kvp.Value, "Request"); TaskStatus status = GetProperty(kvp.Value, "RequestTaskStatus"); Assert.Equal(TaskStatus.Canceled, status); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } }); @@ -344,7 +345,7 @@ public void SendAsync_ExpectedDiagnosticSourceActivityLogging(ActivityIdFormat i activityStopResponseLogged = GetProperty(kvp.Value, "Response"); TaskStatus requestStatus = GetProperty(kvp.Value, "RequestTaskStatus"); Assert.Equal(TaskStatus.RanToCompletion, requestStatus); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } }); @@ -409,7 +410,7 @@ public void SendAsync_ExpectedDiagnosticSourceActivityLogging_InvalidBaggage() Assert.Contains("goodkey=bad%2Fvalue", correlationContext); TaskStatus requestStatus = GetProperty(kvp.Value, "RequestTaskStatus"); Assert.Equal(TaskStatus.RanToCompletion, requestStatus); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } else if (kvp.Key.Equals("System.Net.Http.Exception")) { @@ -467,7 +468,7 @@ public void SendAsync_ExpectedDiagnosticSourceActivityLoggingDoesNotOverwriteHea Assert.False(request.Headers.TryGetValues("traceparent", out var _)); Assert.False(request.Headers.TryGetValues("tracestate", out var _)); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } }); @@ -519,7 +520,7 @@ public void SendAsync_ExpectedDiagnosticSourceActivityLoggingDoesNotOverwriteW3C } else if (kvp.Key.Equals("System.Net.Http.HttpRequestOut.Stop")) { - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } }); @@ -608,7 +609,7 @@ public void SendAsync_ExpectedDiagnosticExceptionActivityLogging() GetProperty(kvp.Value, "Request"); TaskStatus requestStatus = GetProperty(kvp.Value, "RequestTaskStatus"); Assert.Equal(TaskStatus.Faulted, requestStatus); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } else if (kvp.Key.Equals("System.Net.Http.Exception")) { @@ -647,7 +648,7 @@ public void SendAsync_ExpectedDiagnosticSynchronousExceptionActivityLogging() GetProperty(kvp.Value, "Request"); TaskStatus requestStatus = GetProperty(kvp.Value, "RequestTaskStatus"); Assert.Equal(TaskStatus.Faulted, requestStatus); - activityStopTcs.SetResult();; + activityStopTcs.SetResult(); } else if (kvp.Key.Equals("System.Net.Http.Exception")) { @@ -796,44 +797,6 @@ public void SendAsync_ExpectedDiagnosticExceptionOnlyActivityLogging() }, UseVersion.ToString(), TestAsync.ToString()).Dispose(); } - [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] - public void SendAsync_ExpectedActivityPropagationWithoutListener() - { - RemoteExecutor.Invoke(async (useVersion, testAsync) => - { - Activity parent = new Activity("parent").Start(); - - await GetFactoryForVersion(useVersion).CreateClientAndServerAsync( - async uri => - { - await GetAsync(useVersion, testAsync, uri); - }, - async server => - { - HttpRequestData requestData = await server.AcceptConnectionSendResponseAndCloseAsync(); - AssertHeadersAreInjected(requestData, parent); - }); - }, UseVersion.ToString(), TestAsync.ToString()).Dispose(); - } - - [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] - public void SendAsync_ExpectedActivityPropagationWithoutListenerOrParentActivity() - { - RemoteExecutor.Invoke(async (useVersion, testAsync) => - { - await GetFactoryForVersion(useVersion).CreateClientAndServerAsync( - async uri => - { - await GetAsync(useVersion, testAsync, uri); - }, - async server => - { - HttpRequestData requestData = await server.AcceptConnectionSendResponseAndCloseAsync(); - AssertNoHeadersAreInjected(requestData); - }); - }, UseVersion.ToString(), TestAsync.ToString()).Dispose(); - } - [ConditionalTheory(nameof(EnableActivityPropagationEnvironmentVariableIsNotSetAndRemoteExecutorSupported))] [InlineData("true")] [InlineData("1")] @@ -899,6 +862,111 @@ await GetFactoryForVersion(useVersion).CreateClientAndServerAsync( }, UseVersion.ToString(), TestAsync.ToString(), switchValue.ToString()).Dispose(); } + [ConditionalTheory(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + [InlineData(true, true, true)] // Activity was set and ActivitySource created an Activity + [InlineData(true, false, true)] // Activity was set and ActivitySource created an Activity + [InlineData(true, null, true)] // Activity was set and ActivitySource created an Activity + [InlineData(true, true, false)] // Activity was set, ActivitySource chose not to create an Activity, so one was manually created + [InlineData(true, false, false)] // Activity was set, ActivitySource chose not to create an Activity, so one was manually created + [InlineData(true, null, false)] // Activity was set, ActivitySource chose not to create an Activity, so one was manually created + [InlineData(true, true, null)] // Activity was set, ActivitySource had no listeners, so an Activity was manually created + [InlineData(true, false, null)] // Activity was set, ActivitySource had no listeners, so an Activity was manually created + [InlineData(true, null, null)] // Activity was set, ActivitySource had no listeners, so an Activity was manually created + [InlineData(false, true, true)] // DiagnosticListener requested an Activity and ActivitySource created an Activity + [InlineData(false, true, false)] // DiagnosticListener requested an Activity, ActivitySource chose not to create an Activity, so one was manually created + [InlineData(false, true, null)] // DiagnosticListener requested an Activity, ActivitySource had no listeners, so an Activity was manually created + [InlineData(false, false, true)] // No Activity is set, DiagnosticListener does not want one, but ActivitySource created an Activity + [InlineData(false, false, false)] // No Activity is set, DiagnosticListener does not want one and ActivitySource chose not to create an Activity + [InlineData(false, false, null)] // No Activity is set, DiagnosticListener does not want one and ActivitySource has no listeners + [InlineData(false, null, true)] // No Activity is set, there is no DiagnosticListener, but ActivitySource created an Activity + [InlineData(false, null, false)] // No Activity is set, there is no DiagnosticListener and ActivitySource chose not to create an Activity + [InlineData(false, null, null)] // No Activity is set, there is no DiagnosticListener and ActivitySource has no listeners + public void SendAsync_ActivityIsCreatedIfRequested(bool currentActivitySet, bool? diagnosticListenerActivityEnabled, bool? activitySourceCreatesActivity) + { + string parameters = $"{currentActivitySet},{diagnosticListenerActivityEnabled},{activitySourceCreatesActivity}"; + + RemoteExecutor.Invoke(async (useVersion, testAsync, parametersString) => + { + bool?[] parameters = parametersString.Split(',').Select(p => p.Length == 0 ? (bool?)null : bool.Parse(p)).ToArray(); + bool currentActivitySet = parameters[0].Value; + bool? diagnosticListenerActivityEnabled = parameters[1]; + bool? activitySourceCreatesActivity = parameters[2]; + + bool madeASamplingDecision = false; + if (activitySourceCreatesActivity.HasValue) + { + ActivitySource.AddActivityListener(new ActivityListener + { + ShouldListenTo = _ => true, + Sample = (ref ActivityCreationOptions _) => + { + madeASamplingDecision = true; + return activitySourceCreatesActivity.Value ? ActivitySamplingResult.AllData : ActivitySamplingResult.None; + } + }); + } + + bool listenerCallbackWasCalled = false; + IDisposable listenerSubscription = new MemoryStream(); // Dummy disposable + if (diagnosticListenerActivityEnabled.HasValue) + { + var diagnosticListenerObserver = new FakeDiagnosticListenerObserver(_ => listenerCallbackWasCalled = true); + + diagnosticListenerObserver.Enable(name => !name.Contains("HttpRequestOut") || diagnosticListenerActivityEnabled.Value); + + listenerSubscription = DiagnosticListener.AllListeners.Subscribe(diagnosticListenerObserver); + } + + Activity activity = currentActivitySet ? new Activity("parent").Start() : null; + + if (!currentActivitySet) + { + // Listen to new activity creations if an Activity was created without a parent + // (when a DiagnosticListener forced one to be created) + ActivitySource.AddActivityListener(new ActivityListener + { + ShouldListenTo = _ => true, + ActivityStarted = created => + { + Assert.Null(activity); + activity = created; + } + }); + } + + using (listenerSubscription) + { + await GetFactoryForVersion(useVersion).CreateClientAndServerAsync( + async uri => + { + await GetAsync(useVersion, testAsync, uri); + }, + async server => + { + HttpRequestData requestData = await server.AcceptConnectionSendResponseAndCloseAsync(); + + if (currentActivitySet || diagnosticListenerActivityEnabled == true || activitySourceCreatesActivity == true) + { + Assert.NotNull(activity); + AssertHeadersAreInjected(requestData, activity); + } + else + { + AssertNoHeadersAreInjected(requestData); + + if (!currentActivitySet) + { + Assert.Null(activity); + } + } + }); + } + + Assert.Equal(activitySourceCreatesActivity.HasValue, madeASamplingDecision); + Assert.Equal(diagnosticListenerActivityEnabled.HasValue, listenerCallbackWasCalled); + }, UseVersion.ToString(), TestAsync.ToString(), parameters).Dispose(); + } + private static T GetProperty(object obj, string propertyName) { Type t = obj.GetType(); diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs index 10e81d5f679199..2c35b9dfaddce6 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs @@ -2903,14 +2903,18 @@ await LoopbackServerFactory.CreateClientAndServerAsync( using HttpClient client = CreateHttpClient(handler); - HttpRequestException hre = await Assert.ThrowsAnyAsync(async () => await client.SendAsync(requestMessage)); + HttpRequestException hre = + await Assert.ThrowsAnyAsync(async () => await client.SendAsync(requestMessage)) + .WaitAsync(TimeSpan.FromSeconds(10)); + Assert.Equal(e, hre.InnerException); }, async server => { try { - await server.AcceptConnectionSendResponseAndCloseAsync(content: "foo"); + await server.AcceptConnectionSendResponseAndCloseAsync(content: "foo") + .WaitAsync(TimeSpan.FromSeconds(15)); } catch { } }, options: options); diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/SocksProxyTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/SocksProxyTest.cs index 821794e9f82d5e..24b8ce369e0fa6 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/SocksProxyTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/SocksProxyTest.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System.Collections.Generic; +using System.Diagnostics; using System.IO; using System.Linq; using System.Net.Test.Common; @@ -35,35 +36,119 @@ public async Task TestLoopbackAsync(string scheme, bool useSsl, bool useAuth, st return; } - await LoopbackServerFactory.CreateClientAndServerAsync( - async uri => - { - using LoopbackSocksServer proxy = useAuth ? LoopbackSocksServer.Create("DOTNET", "424242") : LoopbackSocksServer.Create(); - using HttpClientHandler handler = CreateHttpClientHandler(); - using HttpClient client = CreateHttpClient(handler); + List<(int, long)> times = new List<(int, long)>(); + Stopwatch s = Stopwatch.StartNew(); - handler.Proxy = new WebProxy($"{scheme}://127.0.0.1:{proxy.Port}"); - handler.ServerCertificateCustomValidationCallback = TestHelper.AllowAllCertificates; - - if (useAuth) + try + { + times.Add((0, s.ElapsedMilliseconds)); + await LoopbackServerFactory.CreateClientAndServerAsync( + async uri => + { + times.Add((10, s.ElapsedMilliseconds)); + LoopbackSocksServer proxy = useAuth ? LoopbackSocksServer.Create("DOTNET", "424242") : LoopbackSocksServer.Create(); + try + { + times.Add((11, s.ElapsedMilliseconds)); + HttpClientHandler handler = CreateHttpClientHandler(); + try + { + times.Add((12, s.ElapsedMilliseconds)); + HttpClient client = CreateHttpClient(handler); + try + { + times.Add((13, s.ElapsedMilliseconds)); + + handler.Proxy = new WebProxy($"{scheme}://127.0.0.1:{proxy.Port}"); + handler.ServerCertificateCustomValidationCallback = TestHelper.AllowAllCertificates; + + if (useAuth) + { + handler.Proxy.Credentials = new NetworkCredential("DOTNET", "424242"); + } + + uri = new UriBuilder(uri) { Host = host }.Uri; + + HttpRequestMessage request = CreateRequest(HttpMethod.Get, uri, UseVersion, exactVersion: true); + + times.Add((14, s.ElapsedMilliseconds)); + + HttpResponseMessage response = await client.SendAsync(TestAsync, request); + try + { + times.Add((15, s.ElapsedMilliseconds)); + string responseString = await response.Content.ReadAsStringAsync(); + times.Add((16, s.ElapsedMilliseconds)); + Assert.Equal("Echo", responseString); + times.Add((17, s.ElapsedMilliseconds)); + } + catch + { + times.Add((43, s.ElapsedMilliseconds)); + throw; + } + finally + { + times.Add((36, s.ElapsedMilliseconds)); + response.Dispose(); + times.Add((37, s.ElapsedMilliseconds)); + } + } + catch + { + times.Add((42, s.ElapsedMilliseconds)); + throw; + } + finally + { + times.Add((34, s.ElapsedMilliseconds)); + client.Dispose(); + times.Add((35, s.ElapsedMilliseconds)); + } + } + catch + { + times.Add((41, s.ElapsedMilliseconds)); + throw; + } + finally + { + times.Add((32, s.ElapsedMilliseconds)); + //handler.Dispose(); + times.Add((33, s.ElapsedMilliseconds)); + } + } + catch + { + times.Add((40, s.ElapsedMilliseconds)); + throw; + } + finally + { + times.Add((30, s.ElapsedMilliseconds)); + proxy.Dispose(); + times.Add((31, s.ElapsedMilliseconds)); + } + }, + async server => + { + times.Add((20, s.ElapsedMilliseconds)); + await server.HandleRequestAsync(content: "Echo"); + times.Add((21, s.ElapsedMilliseconds)); + }, + options: new GenericLoopbackOptions { - handler.Proxy.Credentials = new NetworkCredential("DOTNET", "424242"); - } - - uri = new UriBuilder(uri) { Host = host }.Uri; - - HttpRequestMessage request = CreateRequest(HttpMethod.Get, uri, UseVersion, exactVersion: true); - - using HttpResponseMessage response = await client.SendAsync(TestAsync, request); - string responseString = await response.Content.ReadAsStringAsync(); - Assert.Equal("Echo", responseString); - }, - async server => await server.HandleRequestAsync(content: "Echo"), - options: new GenericLoopbackOptions - { - UseSsl = useSsl, - Address = host == "::1" ? IPAddress.IPv6Loopback : IPAddress.Loopback - }); + UseSsl = useSsl, + Address = host == "::1" ? IPAddress.IPv6Loopback : IPAddress.Loopback + }, + times: times, + s: s); + } + catch (Exception ex) + { + times.Add((1, s.ElapsedMilliseconds)); + throw new Exception(string.Join('\n', times.Select(t => $"{t.Item1,2} {t.Item2}")), ex); + } } public static IEnumerable TestExceptionalAsync_MemberData()