From b3847f42ae95cc082a6b28575d4d847187b31a7b Mon Sep 17 00:00:00 2001 From: Miha Zupan Date: Mon, 21 Feb 2022 02:03:05 +0100 Subject: [PATCH] Implement HttpTelemetry for HTTP/3 --- .../System/Net/Http/Http3LoopbackServer.cs | 7 +- .../System/Net/Http/HttpTelemetry.AnyOS.cs | 21 ++- .../src/System/Net/Http/HttpTelemetry.cs | 16 ++ .../SocketsHttpHandler/Http3Connection.cs | 66 +++++-- .../SocketsHttpHandler/Http3RequestStream.cs | 49 ++++- .../SocketsHttpHandler/HttpConnectionPool.cs | 20 +- .../tests/FunctionalTests/TelemetryTest.cs | 176 ++++++++++++------ 7 files changed, 271 insertions(+), 84 deletions(-) diff --git a/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs b/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs index 6361194f0bbfb6..c8b00faad27599 100644 --- a/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs +++ b/src/libraries/Common/tests/System/Net/Http/Http3LoopbackServer.cs @@ -113,7 +113,12 @@ public override Task CreateConnectionAsync(SocketWrap private static Http3Options CreateOptions(GenericLoopbackOptions options) { - Http3Options http3Options = new Http3Options(); + if (options is Http3Options http3Options) + { + return http3Options; + } + + http3Options = new Http3Options(); if (options != null) { http3Options.Address = options.Address; diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.AnyOS.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.AnyOS.cs index 0a7e908bf0c31a..3c9c930f08a171 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.AnyOS.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.AnyOS.cs @@ -1,7 +1,6 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. -using System.Diagnostics; using System.Diagnostics.Tracing; using System.Threading; @@ -16,8 +15,10 @@ internal sealed partial class HttpTelemetry private PollingCounter? _failedRequestsCounter; private PollingCounter? _totalHttp11ConnectionsCounter; private PollingCounter? _totalHttp20ConnectionsCounter; + private PollingCounter? _totalHttp30ConnectionsCounter; private EventCounter? _http11RequestsQueueDurationCounter; private EventCounter? _http20RequestsQueueDurationCounter; + private EventCounter? _http30RequestsQueueDurationCounter; [NonEvent] public void Http11RequestLeftQueue(double timeOnQueueMilliseconds) @@ -33,6 +34,13 @@ public void Http20RequestLeftQueue(double timeOnQueueMilliseconds) RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 2, versionMinor: 0); } + [NonEvent] + public void Http30RequestLeftQueue(double timeOnQueueMilliseconds) + { + _http30RequestsQueueDurationCounter!.WriteMetric(timeOnQueueMilliseconds); + RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 3, versionMinor: 0); + } + protected override void OnEventCommand(EventCommandEventArgs command) { if (command.Command == EventCommand.Enable) @@ -87,6 +95,11 @@ protected override void OnEventCommand(EventCommandEventArgs command) DisplayName = "Current Http 2.0 Connections" }; + _totalHttp30ConnectionsCounter ??= new PollingCounter("http30-connections-current-total", this, () => Interlocked.Read(ref _openedHttp30Connections)) + { + DisplayName = "Current Http 3.0 Connections" + }; + _http11RequestsQueueDurationCounter ??= new EventCounter("http11-requests-queue-duration", this) { DisplayName = "HTTP 1.1 Requests Queue Duration", @@ -98,6 +111,12 @@ protected override void OnEventCommand(EventCommandEventArgs command) DisplayName = "HTTP 2.0 Requests Queue Duration", DisplayUnits = "ms" }; + + _http30RequestsQueueDurationCounter ??= new EventCounter("http30-requests-queue-duration", this) + { + DisplayName = "HTTP 3.0 Requests Queue Duration", + DisplayUnits = "ms" + }; } } } diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs index ae52766e081165..9e5e1f56466759 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs @@ -18,6 +18,7 @@ internal sealed partial class HttpTelemetry : EventSource private long _openedHttp11Connections; private long _openedHttp20Connections; + private long _openedHttp30Connections; // NOTE // - The 'Start' and 'Stop' suffixes on the following event names have special meaning in EventSource. They @@ -158,6 +159,21 @@ public void Http20ConnectionClosed() ConnectionClosed(versionMajor: 2, versionMinor: 0); } + [NonEvent] + public void Http30ConnectionEstablished() + { + Interlocked.Increment(ref _openedHttp30Connections); + ConnectionEstablished(versionMajor: 3, versionMinor: 0); + } + + [NonEvent] + public void Http30ConnectionClosed() + { + long count = Interlocked.Decrement(ref _openedHttp30Connections); + Debug.Assert(count >= 0); + ConnectionClosed(versionMajor: 3, versionMinor: 0); + } + #if !ES_BUILD_STANDALONE [System.Diagnostics.CodeAnalysis.UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode", Justification = "Parameters to this method are primitive and are trimmer safe")] diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3Connection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3Connection.cs index 3c053ca92620ed..e4269e4e9f2dbf 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3Connection.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3Connection.cs @@ -12,6 +12,7 @@ using System.Globalization; using System.Net.Http.Headers; using System.Net.Security; +using Microsoft.Extensions.Internal; namespace System.Net.Http { @@ -47,6 +48,10 @@ internal sealed class Http3Connection : HttpConnectionBase // A connection-level error will abort any future operations. private Exception? _abortException; + private const int TelemetryStatus_Opened = 1; + private const int TelemetryStatus_Closed = 2; + private int _markedByTelemetryStatus; + public HttpAuthority Authority => _authority; public HttpConnectionPool Pool => _pool; public int MaximumRequestHeadersLength => _maximumHeadersLength; @@ -77,6 +82,12 @@ public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAutho string altUsedValue = altUsedDefaultPort ? authority.IdnHost : string.Create(CultureInfo.InvariantCulture, $"{authority.IdnHost}:{authority.Port}"); _altUsedEncodedHeader = QPack.QPackEncoder.EncodeLiteralHeaderFieldWithoutNameReferenceToArray(KnownHeaders.AltUsed.Name, altUsedValue); + if (HttpTelemetry.Log.IsEnabled()) + { + HttpTelemetry.Log.Http30ConnectionEstablished(); + _markedByTelemetryStatus = TelemetryStatus_Opened; + } + // Errors are observed via Abort(). _ = SendSettingsAsync(); @@ -148,13 +159,19 @@ private void CheckForShutdown() } }, CancellationToken.None, TaskContinuationOptions.ExecuteSynchronously, TaskScheduler.Default); + + if (HttpTelemetry.Log.IsEnabled()) + { + if (Interlocked.Exchange(ref _markedByTelemetryStatus, TelemetryStatus_Closed) == TelemetryStatus_Opened) + { + HttpTelemetry.Log.Http30ConnectionClosed(); + } + } } } - public async Task SendAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) + public async Task SendAsync(HttpRequestMessage request, ValueStopwatch queueDuration, CancellationToken cancellationToken) { - Debug.Assert(async); - // Allocate an active request QuicStream? quicStream = null; Http3RequestStream? requestStream = null; @@ -162,27 +179,44 @@ public async Task SendAsync(HttpRequestMessage request, boo try { - while (true) + try { - lock (SyncObj) + while (true) { - if (_connection == null) + lock (SyncObj) { - break; + if (_connection == null) + { + break; + } + + if (_connection.GetRemoteAvailableBidirectionalStreamCount() > 0) + { + quicStream = _connection.OpenBidirectionalStream(); + requestStream = new Http3RequestStream(request, this, quicStream); + _activeRequests.Add(quicStream, requestStream); + break; + } + + waitTask = _connection.WaitForAvailableBidirectionalStreamsAsync(cancellationToken); } - if (_connection.GetRemoteAvailableBidirectionalStreamCount() > 0) + if (HttpTelemetry.Log.IsEnabled() && !waitTask.IsCompleted && !queueDuration.IsActive) { - quicStream = _connection.OpenBidirectionalStream(); - requestStream = new Http3RequestStream(request, this, quicStream); - _activeRequests.Add(quicStream, requestStream); - break; + // We avoid logging RequestLeftQueue if a stream was available immediately (synchronously) + queueDuration = ValueStopwatch.StartNew(); } - waitTask = _connection.WaitForAvailableBidirectionalStreamsAsync(cancellationToken); - } - // Wait for an available stream (based on QUIC MAX_STREAMS) if there isn't one available yet. - await waitTask.ConfigureAwait(false); + // Wait for an available stream (based on QUIC MAX_STREAMS) if there isn't one available yet. + await waitTask.ConfigureAwait(false); + } + } + finally + { + if (HttpTelemetry.Log.IsEnabled() && queueDuration.IsActive) + { + HttpTelemetry.Log.Http30RequestLeftQueue(queueDuration.GetElapsedTime().TotalMilliseconds); + } } if (quicStream == null) diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs index 6e3c0f17fe40ac..410f050729d03e 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3RequestStream.cs @@ -283,7 +283,7 @@ await Task.WhenAny(sendContentTask, readResponseTask).ConfigureAwait(false) == s if (cancellationToken.IsCancellationRequested) { _stream.AbortWrite((long)Http3ErrorCode.RequestCancelled); - throw new OperationCanceledException(ex.Message, ex, cancellationToken); + throw new TaskCanceledException(ex.Message, ex, cancellationToken); } else { @@ -321,6 +321,8 @@ await Task.WhenAny(sendContentTask, readResponseTask).ConfigureAwait(false) == s /// private async Task ReadResponseAsync(CancellationToken cancellationToken) { + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStart(); + Debug.Assert(_response == null); do { @@ -343,6 +345,8 @@ private async Task ReadResponseAsync(CancellationToken cancellationToken) while ((int)_response.StatusCode < 200); _headerState = HeaderState.TrailingHeaders; + + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.ResponseHeadersStop(); } private async Task SendContentAsync(HttpContent content, CancellationToken cancellationToken) @@ -376,13 +380,20 @@ private async Task SendContentAsync(HttpContent content, CancellationToken cance } } + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStart(); + // If we have a Content-Length, keep track of it so we don't over-send and so we can send in a single DATA frame. _requestContentLengthRemaining = content.Headers.ContentLength ?? -1; - using (var writeStream = new Http3WriteStream(this)) + var writeStream = new Http3WriteStream(this); + try { await content.CopyToAsync(writeStream, null, cancellationToken).ConfigureAwait(false); } + finally + { + writeStream.Dispose(); + } if (_requestContentLengthRemaining > 0) { @@ -406,6 +417,8 @@ private async Task SendContentAsync(HttpContent content, CancellationToken cance { _stream.Shutdown(); } + + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestContentStop(writeStream.BytesWritten); } private async ValueTask WriteRequestContentAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken) @@ -530,6 +543,8 @@ private void CopyTrailersToResponseMessage(HttpResponseMessage responseMessage) private void BufferHeaders(HttpRequestMessage request) { + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(); + // Reserve space for the header frame envelope. // The envelope needs to be written after headers are serialized, as we need to know the payload length first. const int PreHeadersReserveSpace = Http3Frame.MaximumEncodedFrameEnvelopeLength; @@ -617,6 +632,8 @@ private void BufferHeaders(HttpRequestMessage request) _sendBuffer.ActiveSpan[0] = (byte)Http3FrameType.Headers; int actualHeadersLengthEncodedSize = VariableLengthIntegerHelper.WriteInteger(_sendBuffer.ActiveSpan.Slice(1, headersLengthEncodedSize), headersLength); Debug.Assert(actualHeadersLengthEncodedSize == headersLengthEncodedSize); + + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStop(); } // TODO: special-case Content-Type for static table values values? @@ -1344,24 +1361,28 @@ public override async ValueTask DisposeAsync() public override int Read(Span buffer) { - if (_stream == null) + Http3RequestStream? stream = _stream; + + if (stream is null) { throw new ObjectDisposedException(nameof(Http3RequestStream)); } Debug.Assert(_response != null); - return _stream.ReadResponseContent(_response, buffer); + return stream.ReadResponseContent(_response, buffer); } public override ValueTask ReadAsync(Memory buffer, CancellationToken cancellationToken) { - if (_stream == null) + Http3RequestStream? stream = _stream; + + if (stream is null) { return ValueTask.FromException(new ObjectDisposedException(nameof(Http3RequestStream))); } Debug.Assert(_response != null); - return _stream.ReadResponseContentAsync(_response, buffer, cancellationToken); + return stream.ReadResponseContentAsync(_response, buffer, cancellationToken); } public override ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken) @@ -1375,6 +1396,8 @@ private sealed class Http3WriteStream : HttpBaseStream { private Http3RequestStream? _stream; + public long BytesWritten { get; private set; } + public override bool CanRead => false; public override bool CanWrite => _stream != null; @@ -1402,22 +1425,28 @@ public override ValueTask ReadAsync(Memory buffer, CancellationToken public override ValueTask WriteAsync(ReadOnlyMemory buffer, CancellationToken cancellationToken) { - if (_stream == null) + BytesWritten += buffer.Length; + + Http3RequestStream? stream = _stream; + + if (stream is null) { return ValueTask.FromException(new ObjectDisposedException(nameof(Http3WriteStream))); } - return _stream.WriteRequestContentAsync(buffer, cancellationToken); + return stream.WriteRequestContentAsync(buffer, cancellationToken); } public override Task FlushAsync(CancellationToken cancellationToken) { - if (_stream == null) + Http3RequestStream? stream = _stream; + + if (stream is null) { return Task.FromException(new ObjectDisposedException(nameof(Http3WriteStream))); } - return _stream.FlushSendBufferAsync(endStream: false, cancellationToken).AsTask(); + return stream.FlushSendBufferAsync(endStream: false, cancellationToken).AsTask(); } } diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs index 39b7b3006ee122..53ff4734edc800 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs @@ -902,7 +902,7 @@ private async ValueTask GetHttp3ConnectionAsync(HttpRequestMess [SupportedOSPlatform("windows")] [SupportedOSPlatform("linux")] [SupportedOSPlatform("macos")] - private async ValueTask TrySendUsingHttp3Async(HttpRequestMessage request, bool async, CancellationToken cancellationToken) + private async ValueTask TrySendUsingHttp3Async(HttpRequestMessage request, CancellationToken cancellationToken) { // Loop in case we get a 421 and need to send the request to a different authority. while (true) @@ -925,8 +925,19 @@ private async ValueTask GetHttp3ConnectionAsync(HttpRequestMess ThrowGetVersionException(request, 3); } - Http3Connection connection = await GetHttp3ConnectionAsync(request, authority, cancellationToken).ConfigureAwait(false); - HttpResponseMessage response = await connection.SendAsync(request, async, cancellationToken).ConfigureAwait(false); + ValueStopwatch queueDuration = HttpTelemetry.Log.IsEnabled() ? ValueStopwatch.StartNew() : default; + + ValueTask connectionTask = GetHttp3ConnectionAsync(request, authority, cancellationToken); + + if (HttpTelemetry.Log.IsEnabled() && connectionTask.IsCompleted) + { + // We avoid logging RequestLeftQueue if a stream was available immediately (synchronously) + queueDuration = default; + } + + Http3Connection connection = await connectionTask.ConfigureAwait(false); + + HttpResponseMessage response = await connection.SendAsync(request, queueDuration, cancellationToken).ConfigureAwait(false); // If an Alt-Svc authority returns 421, it means it can't actually handle the request. // An authority is supposed to be able to handle ALL requests to the origin, so this is a server bug. @@ -966,7 +977,8 @@ public async ValueTask SendWithVersionDetectionAndRetryAsyn _http3Enabled && (request.Version.Major >= 3 || (request.VersionPolicy == HttpVersionPolicy.RequestVersionOrHigher && IsSecure))) { - response = await TrySendUsingHttp3Async(request, async, cancellationToken).ConfigureAwait(false); + Debug.Assert(async); + response = await TrySendUsingHttp3Async(request, cancellationToken).ConfigureAwait(false); } if (response is null) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 9cbba2ad0382fb..40c208cd21855d 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -6,6 +6,8 @@ using System.Diagnostics.Tracing; using System.IO; using System.Linq; +using System.Net.Quic; +using System.Net.Quic.Implementations; using System.Net.Test.Common; using System.Text; using System.Threading; @@ -20,6 +22,13 @@ public abstract class TelemetryTest : HttpClientHandlerTestBase { public TelemetryTest(ITestOutputHelper output) : base(output) { } + private string QuicImplementationProvider => UseQuicImplementationProvider?.GetType().Name ?? string.Empty; + + private static QuicImplementationProvider GetQuicImplementationProvider(string provider) => + provider.Contains(nameof(QuicImplementationProviders.MsQuic)) ? QuicImplementationProviders.MsQuic : + provider.Contains(nameof(QuicImplementationProviders.Mock)) ? QuicImplementationProviders.Mock : + null; + [Fact] public static void EventSource_ExistsWithCorrectId() { @@ -58,7 +67,7 @@ public void EventSource_SuccessfulRequest_LogsStartStop(string testMethod) return; } - RemoteExecutor.Invoke(async (useVersionString, testMethod) => + RemoteExecutor.Invoke(static async (useVersionString, quicProvider, testMethod) => { const int ResponseContentLength = 42; @@ -70,10 +79,10 @@ public void EventSource_SuccessfulRequest_LogsStartStop(string testMethod) var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { - await GetFactoryForVersion(version).CreateClientAndServerAsync( + await GetFactoryForVersion(version, GetQuicImplementationProvider(quicProvider)).CreateClientAndServerAsync( async uri => { - using HttpClientHandler handler = CreateHttpClientHandler(useVersionString); + using HttpClientHandler handler = CreateHttpClientHandler(version, GetQuicImplementationProvider(quicProvider)); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -101,7 +110,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( case "UnbufferedSend": { buffersResponse = false; - HttpResponseMessage response = await Task.Run(() => client.Send(request, HttpCompletionOption.ResponseHeadersRead)); + using HttpResponseMessage response = await Task.Run(() => client.Send(request, HttpCompletionOption.ResponseHeadersRead)); response.Content.CopyTo(Stream.Null, null, default); } break; @@ -116,7 +125,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( case "UnbufferedSendAsync": { buffersResponse = false; - HttpResponseMessage response = await client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead); + using HttpResponseMessage response = await client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead); await response.Content.CopyToAsync(Stream.Null); } break; @@ -138,7 +147,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( case "GetStreamAsync": { buffersResponse = false; - Stream responseStream = await client.GetStreamAsync(uri); + using Stream responseStream = await client.GetStreamAsync(uri); await responseStream.CopyToAsync(Stream.Null); } break; @@ -146,7 +155,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( case "InvokerSend": { buffersResponse = false; - HttpResponseMessage response = await Task.Run(() => invoker.Send(request, cancellationToken: default)); + using HttpResponseMessage response = await Task.Run(() => invoker.Send(request, cancellationToken: default)); await response.Content.CopyToAsync(Stream.Null); } break; @@ -154,7 +163,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( case "InvokerSendAsync": { buffersResponse = false; - HttpResponseMessage response = await invoker.SendAsync(request, cancellationToken: default); + using HttpResponseMessage response = await invoker.SendAsync(request, cancellationToken: default); await response.Content.CopyToAsync(Stream.Null); } break; @@ -164,8 +173,8 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( { await server.AcceptConnectionAsync(async connection => { - await WaitForEventCountersAsync(events); await connection.ReadRequestDataAsync(); + await WaitForEventCountersAsync(events); await connection.SendResponseAsync(content: new string('a', ResponseContentLength)); }); }); @@ -174,7 +183,7 @@ await server.AcceptConnectionAsync(async connection => }); Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself - ValidateStartFailedStopEvents(events); + ValidateStartFailedStopEvents(events, version); ValidateConnectionEstablishedClosed(events, version); @@ -184,8 +193,8 @@ await server.AcceptConnectionAsync(async connection => responseContentLength: buffersResponse ? ResponseContentLength : null, count: 1); - ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: false); - }, UseVersion.ToString(), testMethod).Dispose(); + ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: false, versionMajor: version.Major); + }, UseVersion.ToString(), QuicImplementationProvider, testMethod).Dispose(); } [OuterLoop] @@ -199,7 +208,7 @@ public void EventSource_UnsuccessfulRequest_LogsStartFailedStop(string testMetho return; } - RemoteExecutor.Invoke(async (useVersionString, testMethod) => + RemoteExecutor.Invoke(static async (useVersionString, quicProvider, testMethod) => { Version version = Version.Parse(useVersionString); using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); @@ -211,10 +220,10 @@ await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), asyn var semaphore = new SemaphoreSlim(0, 1); var cts = new CancellationTokenSource(); - await GetFactoryForVersion(version).CreateClientAndServerAsync( + await GetFactoryForVersion(version, GetQuicImplementationProvider(quicProvider)).CreateClientAndServerAsync( async uri => { - using HttpClientHandler handler = CreateHttpClientHandler(useVersionString); + using HttpClientHandler handler = CreateHttpClientHandler(version, GetQuicImplementationProvider(quicProvider)); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -283,12 +292,12 @@ await server.AcceptConnectionAsync(async connection => }); Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself - ValidateStartFailedStopEvents(events, shouldHaveFailures: true); + ValidateStartFailedStopEvents(events, version, shouldHaveFailures: true); ValidateConnectionEstablishedClosed(events, version); - ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: true); - }, UseVersion.ToString(), testMethod).Dispose(); + ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: true, versionMajor: version.Major); + }, UseVersion.ToString(), QuicImplementationProvider, testMethod).Dispose(); } [OuterLoop] @@ -307,7 +316,7 @@ public void EventSource_SendingRequestContent_LogsRequestContentStartStop(string return; } - RemoteExecutor.Invoke(async (useVersionString, testMethod) => + RemoteExecutor.Invoke(static async (useVersionString, quicProvider, testMethod) => { const int RequestContentLength = 42; const int ResponseContentLength = 43; @@ -319,10 +328,10 @@ public void EventSource_SendingRequestContent_LogsRequestContentStartStop(string var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { - await GetFactoryForVersion(version).CreateClientAndServerAsync( + await GetFactoryForVersion(version, GetQuicImplementationProvider(quicProvider)).CreateClientAndServerAsync( async uri => { - using HttpClientHandler handler = CreateHttpClientHandler(useVersionString); + using HttpClientHandler handler = CreateHttpClientHandler(version, GetQuicImplementationProvider(quicProvider)); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -368,8 +377,8 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( { await server.AcceptConnectionAsync(async connection => { - await WaitForEventCountersAsync(events); await connection.ReadRequestDataAsync(); + await WaitForEventCountersAsync(events); await connection.SendResponseAsync(content: new string('a', ResponseContentLength)); }); }); @@ -378,7 +387,7 @@ await server.AcceptConnectionAsync(async connection => }); Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself - ValidateStartFailedStopEvents(events); + ValidateStartFailedStopEvents(events, version); ValidateConnectionEstablishedClosed(events, version); @@ -388,11 +397,11 @@ await server.AcceptConnectionAsync(async connection => responseContentLength: testMethod.StartsWith("InvokerSend") ? null : ResponseContentLength, count: 1); - ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: false); - }, UseVersion.ToString(), testMethod).Dispose(); + ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: false, versionMajor: version.Major); + }, UseVersion.ToString(), QuicImplementationProvider, testMethod).Dispose(); } - private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, bool shouldHaveFailures = false, int count = 1) + private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, bool shouldHaveFailures = false, int count = 1) { (EventWrittenEventArgs Event, Guid ActivityId)[] starts = events.Where(e => e.Event.EventName == "RequestStart").ToArray(); foreach (EventWrittenEventArgs startEvent in starts.Select(e => e.Event)) @@ -402,8 +411,10 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE Assert.NotEmpty((string)startEvent.Payload[1]); // host Assert.True(startEvent.Payload[2] is int port && port >= 0 && port <= 65535); Assert.NotEmpty((string)startEvent.Payload[3]); // pathAndQuery - Assert.True(startEvent.Payload[4] is byte versionMajor && (versionMajor == 1 || versionMajor == 2)); - Assert.True(startEvent.Payload[5] is byte versionMinor && (versionMinor == 1 || versionMinor == 0)); + byte versionMajor = Assert.IsType(startEvent.Payload[4]); + Assert.Equal(version.Major, versionMajor); + byte versionMinor = Assert.IsType(startEvent.Payload[5]); + Assert.Equal(version.Minor, versionMinor); Assert.InRange((HttpVersionPolicy)startEvent.Payload[6], HttpVersionPolicy.RequestVersionOrLower, HttpVersionPolicy.RequestVersionExact); } Assert.Equal(count, starts.Length); @@ -505,7 +516,7 @@ private static void ValidateSameActivityIds((EventWrittenEventArgs Event, Guid A } } - private static void ValidateEventCounters(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, int requestCount, bool shouldHaveFailures, int requestsLeftQueueVersion = -1) + private static void ValidateEventCounters(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, int requestCount, bool shouldHaveFailures, int versionMajor, bool requestLeftQueue = false) { Dictionary eventCounters = events .Select(e => e.Event) @@ -545,20 +556,61 @@ private static void ValidateEventCounters(ConcurrentQueue<(EventWrittenEventArgs Assert.All(http20ConnectionsTotal, c => Assert.True(c >= 0)); Assert.Equal(0, http20ConnectionsTotal[^1]); - Assert.True(eventCounters.TryGetValue("http11-requests-queue-duration", out double[] http11requestQueueDurations)); - Assert.Equal(0, http11requestQueueDurations[^1]); - if (requestsLeftQueueVersion == 1) + Assert.True(eventCounters.TryGetValue("http30-connections-current-total", out double[] http30ConnectionsTotal)); + Assert.All(http30ConnectionsTotal, c => Assert.True(c >= 0)); + Assert.Equal(0, http30ConnectionsTotal[^1]); + + if (versionMajor == 1) + { + Assert.Contains(http11ConnectionsTotal, d => d > 0); + Assert.DoesNotContain(http20ConnectionsTotal, d => d > 0); + Assert.DoesNotContain(http30ConnectionsTotal, d => d > 0); + } + else if (versionMajor == 2) { - Assert.Contains(http11requestQueueDurations, d => d > 0); - Assert.All(http11requestQueueDurations, d => Assert.True(d >= 0)); + Assert.DoesNotContain(http11ConnectionsTotal, d => d > 0); + Assert.Contains(http20ConnectionsTotal, d => d > 0); + Assert.DoesNotContain(http30ConnectionsTotal, d => d > 0); } + else + { + Assert.DoesNotContain(http11ConnectionsTotal, d => d > 0); + Assert.DoesNotContain(http20ConnectionsTotal, d => d > 0); + Assert.Contains(http30ConnectionsTotal, d => d > 0); + } + + Assert.True(eventCounters.TryGetValue("http11-requests-queue-duration", out double[] http11requestQueueDurations)); + Assert.All(http11requestQueueDurations, d => Assert.True(d >= 0)); + Assert.Equal(0, http11requestQueueDurations[^1]); Assert.True(eventCounters.TryGetValue("http20-requests-queue-duration", out double[] http20requestQueueDurations)); + Assert.All(http20requestQueueDurations, d => Assert.True(d >= 0)); Assert.Equal(0, http20requestQueueDurations[^1]); - if (requestsLeftQueueVersion == 2) + + Assert.True(eventCounters.TryGetValue("http30-requests-queue-duration", out double[] http30requestQueueDurations)); + Assert.All(http30requestQueueDurations, d => Assert.True(d >= 0)); + Assert.Equal(0, http30requestQueueDurations[^1]); + + if (requestLeftQueue) { - Assert.Contains(http20requestQueueDurations, d => d > 0); - Assert.All(http20requestQueueDurations, d => Assert.True(d >= 0)); + if (versionMajor == 1) + { + Assert.Contains(http11requestQueueDurations, d => d > 0); + Assert.DoesNotContain(http20requestQueueDurations, d => d > 0); + Assert.DoesNotContain(http30requestQueueDurations, d => d > 0); + } + else if (versionMajor == 2) + { + Assert.DoesNotContain(http11requestQueueDurations, d => d > 0); + Assert.Contains(http20requestQueueDurations, d => d > 0); + Assert.DoesNotContain(http30requestQueueDurations, d => d > 0); + } + else + { + Assert.DoesNotContain(http11requestQueueDurations, d => d > 0); + Assert.DoesNotContain(http20requestQueueDurations, d => d > 0); + Assert.Contains(http30requestQueueDurations, d => d > 0); + } } } @@ -566,7 +618,12 @@ private static void ValidateEventCounters(ConcurrentQueue<(EventWrittenEventArgs [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] public void EventSource_ConnectionPoolAtMaxConnections_LogsRequestLeftQueue() { - RemoteExecutor.Invoke(async useVersionString => + if (UseVersion.Major == 3 && UseQuicImplementationProvider == QuicImplementationProviders.Mock) + { + return; + } + + RemoteExecutor.Invoke(static async (useVersionString, quicProvider) => { Version version = Version.Parse(useVersionString); using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); @@ -579,14 +636,15 @@ await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), asyn var secondRequestSent = new SemaphoreSlim(0, 1); var firstRequestFinished = new SemaphoreSlim(0, 1); - await GetFactoryForVersion(version).CreateClientAndServerAsync( + await GetFactoryForVersion(version, GetQuicImplementationProvider(quicProvider)).CreateClientAndServerAsync( async uri => { - using HttpClientHandler handler = CreateHttpClientHandler(useVersionString); + using HttpClientHandler handler = CreateHttpClientHandler(version, GetQuicImplementationProvider(quicProvider)); using HttpClient client = CreateHttpClient(handler, useVersionString); - var socketsHttpHandler = GetUnderlyingSocketsHttpHandler(handler) as SocketsHttpHandler; + var socketsHttpHandler = GetUnderlyingSocketsHttpHandler(handler); socketsHttpHandler.MaxConnectionsPerServer = 1; + socketsHttpHandler.SslOptions.RemoteCertificateValidationCallback = delegate { return true; }; // Dummy request to ensure that the MaxConcurrentStreams setting has been acknowledged await client.GetStringAsync(uri); @@ -609,9 +667,9 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( async server => { GenericLoopbackConnection connection; + if (server is Http2LoopbackServer http2Server) { - http2Server.AllowMultipleConnections = true; connection = await http2Server.EstablishConnectionAsync(new SettingsEntry { SettingId = SettingId.MaxConcurrentStreams, Value = 1 }); } else @@ -637,35 +695,34 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( await connection.ReadRequestDataAsync(readBody: false); await connection.SendResponseAsync(); }; - }); + }, options: new Http3Options { MaxBidirectionalStreams = 1 }); await WaitForEventCountersAsync(events); }); Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself - ValidateStartFailedStopEvents(events, count: 3); + ValidateStartFailedStopEvents(events, version, count: 3); ValidateConnectionEstablishedClosed(events, version); - var requestLeftEvents = events.Where(e => e.Event.EventName == "RequestLeftQueue"); - Assert.Equal(2, requestLeftEvents.Count()); + var requestLeftQueueEvents = events.Where(e => e.Event.EventName == "RequestLeftQueue"); + Assert.InRange(requestLeftQueueEvents.Count(), 2, version.Major == 3 ? 3 : 2); - foreach (var (e, _) in requestLeftEvents) + foreach (var (e, _) in requestLeftQueueEvents) { Assert.Equal(3, e.Payload.Count); Assert.True((double)e.Payload[0] > 0); // timeSpentOnQueue Assert.Equal(version.Major, (byte)e.Payload[1]); Assert.Equal(version.Minor, (byte)e.Payload[2]); - } - Guid requestLeftQueueId = requestLeftEvents.Last().ActivityId; + Guid requestLeftQueueId = requestLeftQueueEvents.Last().ActivityId; Assert.Equal(requestLeftQueueId, events.Where(e => e.Event.EventName == "RequestStart").Last().ActivityId); ValidateRequestResponseStartStopEvents(events, requestContentLength: null, responseContentLength: 0, count: 3); - ValidateEventCounters(events, requestCount: 3, shouldHaveFailures: false, requestsLeftQueueVersion: version.Major); - }, UseVersion.ToString()).Dispose(); + ValidateEventCounters(events, requestCount: 3, shouldHaveFailures: false, versionMajor: version.Major, requestLeftQueue: true); + }, UseVersion.ToString(), QuicImplementationProvider).Dispose(); } private static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) @@ -701,7 +758,22 @@ public TelemetryTest_Http11(ITestOutputHelper output) : base(output) { } public sealed class TelemetryTest_Http20 : TelemetryTest { protected override Version UseVersion => HttpVersion.Version20; - public TelemetryTest_Http20(ITestOutputHelper output) : base(output) { } } + + [ConditionalClass(typeof(HttpClientHandlerTestBase), nameof(IsMsQuicSupported))] + public sealed class TelemetryTest_Http30_MsQuic : TelemetryTest + { + protected override Version UseVersion => HttpVersion.Version30; + protected override QuicImplementationProvider UseQuicImplementationProvider => QuicImplementationProviders.MsQuic; + public TelemetryTest_Http30_MsQuic(ITestOutputHelper output) : base(output) { } + } + + [ConditionalClass(typeof(HttpClientHandlerTestBase), nameof(IsMockQuicSupported))] + public sealed class TelemetryTest_Http30_Mock : TelemetryTest + { + protected override Version UseVersion => HttpVersion.Version30; + protected override QuicImplementationProvider UseQuicImplementationProvider => QuicImplementationProviders.Mock; + public TelemetryTest_Http30_Mock(ITestOutputHelper output) : base(output) { } + } }