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 8126bda265a335..9989bc4568e617 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 @@ -90,16 +90,23 @@ private void RequestFailed(string exceptionMessage) WriteEvent(eventId: 3, exceptionMessage); } - [Event(4, Level = EventLevel.Informational)] - private void ConnectionEstablished(byte versionMajor, byte versionMinor) + [NonEvent] + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) + { + string? remoteAddress = remoteEndPoint?.Address?.ToString(); + ConnectionEstablished(versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); + } + + [Event(4, Level = EventLevel.Informational, Version = 1)] + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress) { - WriteEvent(eventId: 4, versionMajor, versionMinor); + WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); } - [Event(5, Level = EventLevel.Informational)] - private void ConnectionClosed(byte versionMajor, byte versionMinor) + [Event(5, Level = EventLevel.Informational, Version = 1)] + private void ConnectionClosed(byte versionMajor, byte versionMinor, long connectionId) { - WriteEvent(eventId: 5, versionMajor, versionMinor); + WriteEvent(eventId: 5, versionMajor, versionMinor, connectionId); } [Event(6, Level = EventLevel.Informational)] @@ -108,10 +115,10 @@ private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor, WriteEvent(eventId: 6, timeOnQueueMilliseconds, versionMajor, versionMinor); } - [Event(7, Level = EventLevel.Informational)] - public void RequestHeadersStart() + [Event(7, Level = EventLevel.Informational, Version = 1)] + public void RequestHeadersStart(long connectionId) { - WriteEvent(eventId: 7); + WriteEvent(eventId: 7, connectionId); } [Event(8, Level = EventLevel.Informational)] @@ -162,49 +169,55 @@ private void RequestFailedDetailed(string exception) WriteEvent(eventId: 15, exception); } + [Event(16, Level = EventLevel.Informational)] + public void Redirect(string redirectUri) + { + WriteEvent(eventId: 16, redirectUri); + } + [NonEvent] - public void Http11ConnectionEstablished() + public void Http11ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp11Connections); - ConnectionEstablished(versionMajor: 1, versionMinor: 1); + ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] - public void Http11ConnectionClosed() + public void Http11ConnectionClosed(long connectionId) { long count = Interlocked.Decrement(ref _openedHttp11Connections); Debug.Assert(count >= 0); - ConnectionClosed(versionMajor: 1, versionMinor: 1); + ConnectionClosed(versionMajor: 1, versionMinor: 1, connectionId); } [NonEvent] - public void Http20ConnectionEstablished() + public void Http20ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp20Connections); - ConnectionEstablished(versionMajor: 2, versionMinor: 0); + ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] - public void Http20ConnectionClosed() + public void Http20ConnectionClosed(long connectionId) { long count = Interlocked.Decrement(ref _openedHttp20Connections); Debug.Assert(count >= 0); - ConnectionClosed(versionMajor: 2, versionMinor: 0); + ConnectionClosed(versionMajor: 2, versionMinor: 0, connectionId); } [NonEvent] - public void Http30ConnectionEstablished() + public void Http30ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp30Connections); - ConnectionEstablished(versionMajor: 3, versionMinor: 0); + ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] - public void Http30ConnectionClosed() + public void Http30ConnectionClosed(long connectionId) { long count = Interlocked.Decrement(ref _openedHttp30Connections); Debug.Assert(count >= 0); - ConnectionClosed(versionMajor: 3, versionMinor: 0); + ConnectionClosed(versionMajor: 3, versionMinor: 0, connectionId); } [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode", @@ -293,9 +306,9 @@ private unsafe void WriteEvent(int eventId, double arg1, byte arg2, byte arg3) [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode", Justification = "Parameters to this method are primitive and are trimmer safe")] [NonEvent] - private unsafe void WriteEvent(int eventId, byte arg1, byte arg2) + private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3) { - const int NumEventDatas = 2; + const int NumEventDatas = 3; EventData* descrs = stackalloc EventData[NumEventDatas]; descrs[0] = new EventData @@ -308,6 +321,67 @@ private unsafe void WriteEvent(int eventId, byte arg1, byte arg2) DataPointer = (IntPtr)(&arg2), Size = sizeof(byte) }; + descrs[2] = new EventData + { + DataPointer = (IntPtr)(&arg3), + Size = sizeof(long) + }; + + WriteEventCore(eventId, NumEventDatas, descrs); + } + + [UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode", + Justification = "Parameters to this method are primitive and are trimmer safe")] + [NonEvent] + private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3, string? arg4, string arg5, int arg6, string? arg7) + { + arg4 ??= ""; + arg5 ??= ""; + arg7 ??= ""; + + const int NumEventDatas = 7; + EventData* descrs = stackalloc EventData[NumEventDatas]; + + fixed (char* arg4Ptr = arg4) + fixed (char* arg5Ptr = arg5) + fixed (char* arg7Ptr = arg7) + { + descrs[0] = new EventData + { + DataPointer = (IntPtr)(&arg1), + Size = sizeof(byte) + }; + descrs[1] = new EventData + { + DataPointer = (IntPtr)(&arg2), + Size = sizeof(byte) + }; + descrs[2] = new EventData + { + DataPointer = (IntPtr)(&arg3), + Size = sizeof(long) + }; + descrs[3] = new EventData + { + DataPointer = (IntPtr)arg4Ptr, + Size = (arg4.Length + 1) * sizeof(char) + }; + descrs[4] = new EventData + { + DataPointer = (IntPtr)arg5Ptr, + Size = (arg5.Length + 1) * sizeof(char) + }; + descrs[5] = new EventData + { + DataPointer = (IntPtr)(&arg6), + Size = sizeof(int) + }; + descrs[6] = new EventData + { + DataPointer = (IntPtr)arg7Ptr, + Size = (arg7.Length + 1) * sizeof(char) + }; + } WriteEventCore(eventId, NumEventDatas, descrs); } diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs index 88678ae0b8a976..064825a5bd2fb8 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs @@ -132,8 +132,8 @@ internal enum KeepAliveState private long _keepAlivePingTimeoutTimestamp; private volatile KeepAliveState _keepAliveState; - public Http2Connection(HttpConnectionPool pool, Stream stream) - : base(pool) + public Http2Connection(HttpConnectionPool pool, Stream stream, IPEndPoint? remoteEndPoint) + : base(pool, remoteEndPoint) { _pool = pool; _stream = stream; @@ -1656,7 +1656,7 @@ private async ValueTask SendHeadersAsync(HttpRequestMessage request ArrayBuffer headerBuffer = default; try { - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(Id); // Serialize headers to a temporary buffer, and do as much work to prepare to send the headers as we can // before taking the write lock. 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 33eadf13f725e4..c036399350fc7d 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 @@ -66,7 +66,7 @@ private bool ShuttingDown } public Http3Connection(HttpConnectionPool pool, HttpAuthority authority, QuicConnection connection, bool includeAltUsedHeader) - : base(pool) + : base(pool, connection.RemoteEndPoint) { _pool = pool; _authority = authority; 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 5bb3a2941cd6ff..0469cbce18f92c 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 @@ -552,7 +552,7 @@ private void CopyTrailersToResponseMessage(HttpResponseMessage responseMessage) private void BufferHeaders(HttpRequestMessage request) { - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(_connection.Id); // 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. diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs index 036012a0cf3553..94df26568fb4e8 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs @@ -43,7 +43,7 @@ internal sealed partial class HttpConnection : HttpConnectionBase private static readonly ulong s_http11Bytes = BitConverter.ToUInt64("HTTP/1.1"u8); private readonly HttpConnectionPool _pool; - private readonly Stream _stream; + internal readonly Stream _stream; private readonly TransportContext? _transportContext; private HttpRequestMessage? _currentRequest; @@ -74,8 +74,9 @@ internal sealed partial class HttpConnection : HttpConnectionBase public HttpConnection( HttpConnectionPool pool, Stream stream, - TransportContext? transportContext) - : base(pool) + TransportContext? transportContext, + IPEndPoint? remoteEndPoint) + : base(pool, remoteEndPoint) { Debug.Assert(pool != null); Debug.Assert(stream != null); @@ -517,7 +518,7 @@ public async Task SendAsync(HttpRequestMessage request, boo CancellationTokenRegistration cancellationRegistration = RegisterCancellation(cancellationToken); try { - if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(); + if (HttpTelemetry.Log.IsEnabled()) HttpTelemetry.Log.RequestHeadersStart(Id); WriteHeaders(request, normalizedMethod); diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionBase.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionBase.cs index bf2b4a0a90a2cf..7c656c1c2b9308 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionBase.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionBase.cs @@ -16,6 +16,8 @@ namespace System.Net.Http { internal abstract class HttpConnectionBase : IDisposable, IHttpTrace { + private static long s_connectionCounter = -1; + // May be null if none of the counters were enabled when the connection was established. private readonly ConnectionMetrics? _connectionMetrics; @@ -31,7 +33,9 @@ internal abstract class HttpConnectionBase : IDisposable, IHttpTrace /// Cached string for the last Server header received on this connection. private string? _lastServerHeaderValue; - public HttpConnectionBase(HttpConnectionPool pool) + public long Id { get; } = Interlocked.Increment(ref s_connectionCounter); + + public HttpConnectionBase(HttpConnectionPool pool, IPEndPoint? remoteEndPoint) { Debug.Assert(this is HttpConnection or Http2Connection or Http3Connection); Debug.Assert(pool.Settings._metrics is not null); @@ -66,9 +70,13 @@ public HttpConnectionBase(HttpConnectionPool pool) { _httpTelemetryMarkedConnectionAsOpened = true; - if (this is HttpConnection) HttpTelemetry.Log.Http11ConnectionEstablished(); - else if (this is Http2Connection) HttpTelemetry.Log.Http20ConnectionEstablished(); - else HttpTelemetry.Log.Http30ConnectionEstablished(); + string scheme = pool.IsSecure ? "https" : "http"; + string host = pool.OriginAuthority.HostValue; + int port = pool.OriginAuthority.Port; + + if (this is HttpConnection) HttpTelemetry.Log.Http11ConnectionEstablished(Id, scheme, host, port, remoteEndPoint); + else if (this is Http2Connection) HttpTelemetry.Log.Http20ConnectionEstablished(Id, scheme, host, port, remoteEndPoint); + else HttpTelemetry.Log.Http30ConnectionEstablished(Id, scheme, host, port, remoteEndPoint); } } @@ -81,9 +89,9 @@ public void MarkConnectionAsClosed() // Only decrement the connection count if we counted this connection if (_httpTelemetryMarkedConnectionAsOpened) { - if (this is HttpConnection) HttpTelemetry.Log.Http11ConnectionClosed(); - else if (this is Http2Connection) HttpTelemetry.Log.Http20ConnectionClosed(); - else HttpTelemetry.Log.Http30ConnectionClosed(); + if (this is HttpConnection) HttpTelemetry.Log.Http11ConnectionClosed(Id); + else if (this is Http2Connection) HttpTelemetry.Log.Http20ConnectionClosed(Id); + else HttpTelemetry.Log.Http30ConnectionClosed(Id); } } } @@ -127,7 +135,7 @@ protected void TraceConnection(Stream stream) if (stream is SslStream sslStream) { Trace( - $"{this}. " + + $"{this}. Id:{Id}, " + $"SslProtocol:{sslStream.SslProtocol}, NegotiatedApplicationProtocol:{sslStream.NegotiatedApplicationProtocol}, " + $"NegotiatedCipherSuite:{sslStream.NegotiatedCipherSuite}, CipherAlgorithm:{sslStream.CipherAlgorithm}, CipherStrength:{sslStream.CipherStrength}, " + $"HashAlgorithm:{sslStream.HashAlgorithm}, HashStrength:{sslStream.HashStrength}, " + @@ -136,7 +144,7 @@ protected void TraceConnection(Stream stream) } else { - Trace($"{this}"); + Trace($"{this}. Id:{Id}"); } } 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 f86147c5967401..ebb629a4a74065 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 @@ -8,6 +8,7 @@ using System.IO; using System.Net.Http.Headers; using System.Net.Http.HPack; +using System.Net.Http.Metrics; using System.Net.Http.QPack; using System.Net.Quic; using System.Net.Security; @@ -603,7 +604,7 @@ private bool TryGetPooledHttp11Connection(HttpRequestMessage request, bool async } } - private async Task HandleHttp11Downgrade(HttpRequestMessage request, Stream stream, TransportContext? transportContext, CancellationToken cancellationToken) + private async Task HandleHttp11Downgrade(HttpRequestMessage request, Stream stream, TransportContext? transportContext, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken) { if (NetEventSource.Log.IsEnabled()) Trace("Server does not support HTTP2; disabling HTTP2 use and proceeding with HTTP/1.1 connection"); @@ -660,7 +661,7 @@ private async Task HandleHttp11Downgrade(HttpRequestMessage request, Stream stre try { // Note, the same CancellationToken from the original HTTP2 connection establishment still applies here. - http11Connection = await ConstructHttp11ConnectionAsync(true, stream, transportContext, request, cancellationToken).ConfigureAwait(false); + http11Connection = await ConstructHttp11ConnectionAsync(true, stream, transportContext, request, remoteEndPoint, cancellationToken).ConfigureAwait(false); } catch (OperationCanceledException oce) when (oce.CancellationToken == cancellationToken) { @@ -692,7 +693,7 @@ private async Task AddHttp2ConnectionAsync(RequestQueue.QueueI waiter.ConnectionCancellationTokenSource = cts; try { - (Stream stream, TransportContext? transportContext) = await ConnectAsync(queueItem.Request, true, cts.Token).ConfigureAwait(false); + (Stream stream, TransportContext? transportContext, IPEndPoint? remoteEndPoint) = await ConnectAsync(queueItem.Request, true, cts.Token).ConfigureAwait(false); if (IsSecure) { @@ -709,19 +710,19 @@ private async Task AddHttp2ConnectionAsync(RequestQueue.QueueI } else { - connection = await ConstructHttp2ConnectionAsync(stream, queueItem.Request, cts.Token).ConfigureAwait(false); + connection = await ConstructHttp2ConnectionAsync(stream, queueItem.Request, remoteEndPoint, cts.Token).ConfigureAwait(false); } } else { // We established an SSL connection, but the server denied our request for HTTP2. - await HandleHttp11Downgrade(queueItem.Request, stream, transportContext, cts.Token).ConfigureAwait(false); + await HandleHttp11Downgrade(queueItem.Request, stream, transportContext, remoteEndPoint, cts.Token).ConfigureAwait(false); return; } } else { - connection = await ConstructHttp2ConnectionAsync(stream, queueItem.Request, cts.Token).ConfigureAwait(false); + connection = await ConstructHttp2ConnectionAsync(stream, queueItem.Request, remoteEndPoint, cts.Token).ConfigureAwait(false); } } catch (Exception e) @@ -1533,15 +1534,18 @@ public ValueTask SendAsync(HttpRequestMessage request, bool private CancellationTokenSource GetConnectTimeoutCancellationTokenSource() => new CancellationTokenSource(Settings._connectTimeout); - private async ValueTask<(Stream, TransportContext?)> ConnectAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) + private async ValueTask<(Stream, TransportContext?, IPEndPoint?)> ConnectAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) { Stream? stream = null; + IPEndPoint? remoteEndPoint = null; switch (_kind) { case HttpConnectionKind.Http: case HttpConnectionKind.Https: case HttpConnectionKind.ProxyConnect: stream = await ConnectToTcpHostAsync(_originAuthority.IdnHost, _originAuthority.Port, request, async, cancellationToken).ConfigureAwait(false); + // remoteEndPoint is returned for diagnostic purposes. + remoteEndPoint = GetRemoteEndPoint(stream); if (_kind == HttpConnectionKind.ProxyConnect && _sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1550,6 +1554,8 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.Proxy: stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false); + // remoteEndPoint is returned for diagnostic purposes. + remoteEndPoint = GetRemoteEndPoint(stream); if (_sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1559,12 +1565,20 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.ProxyTunnel: case HttpConnectionKind.SslProxyTunnel: stream = await EstablishProxyTunnelAsync(async, cancellationToken).ConfigureAwait(false); + + if (stream is HttpContentStream contentStream && contentStream._connection?._stream is Stream innerStream) + { + remoteEndPoint = GetRemoteEndPoint(innerStream); + } + break; case HttpConnectionKind.SocksTunnel: case HttpConnectionKind.SslSocksTunnel: stream = await EstablishSocksTunnel(request, async, cancellationToken).ConfigureAwait(false); - break; + // remoteEndPoint is returned for diagnostic purposes. + remoteEndPoint = GetRemoteEndPoint(stream); + break; } Debug.Assert(stream != null); @@ -1588,7 +1602,9 @@ public ValueTask SendAsync(HttpRequestMessage request, bool stream = sslStream; } - return (stream, transportContext); + static IPEndPoint? GetRemoteEndPoint(Stream stream) => (stream as NetworkStream)?.Socket?.RemoteEndPoint as IPEndPoint; + + return (stream, transportContext, remoteEndPoint); } private async ValueTask ConnectToTcpHostAsync(string host, int port, HttpRequestMessage initialRequest, bool async, CancellationToken cancellationToken) @@ -1654,8 +1670,8 @@ private async ValueTask ConnectToTcpHostAsync(string host, int port, Htt internal async ValueTask CreateHttp11ConnectionAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) { - (Stream stream, TransportContext? transportContext) = await ConnectAsync(request, async, cancellationToken).ConfigureAwait(false); - return await ConstructHttp11ConnectionAsync(async, stream, transportContext, request, cancellationToken).ConfigureAwait(false); + (Stream stream, TransportContext? transportContext, IPEndPoint? remoteEndPoint) = await ConnectAsync(request, async, cancellationToken).ConfigureAwait(false); + return await ConstructHttp11ConnectionAsync(async, stream, transportContext, request, remoteEndPoint, cancellationToken).ConfigureAwait(false); } private SslClientAuthenticationOptions GetSslOptionsForRequest(HttpRequestMessage request) @@ -1718,17 +1734,17 @@ private async ValueTask ApplyPlaintextFilterAsync(bool async, Stream str return newStream; } - private async ValueTask ConstructHttp11ConnectionAsync(bool async, Stream stream, TransportContext? transportContext, HttpRequestMessage request, CancellationToken cancellationToken) + private async ValueTask ConstructHttp11ConnectionAsync(bool async, Stream stream, TransportContext? transportContext, HttpRequestMessage request, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken) { Stream newStream = await ApplyPlaintextFilterAsync(async, stream, HttpVersion.Version11, request, cancellationToken).ConfigureAwait(false); - return new HttpConnection(this, newStream, transportContext); + return new HttpConnection(this, newStream, transportContext, remoteEndPoint); } - private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, CancellationToken cancellationToken) + private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken) { stream = await ApplyPlaintextFilterAsync(async: true, stream, HttpVersion.Version20, request, cancellationToken).ConfigureAwait(false); - Http2Connection http2Connection = new Http2Connection(this, stream); + Http2Connection http2Connection = new Http2Connection(this, stream, remoteEndPoint); try { await http2Connection.SetupAsync(cancellationToken).ConfigureAwait(false); diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpContentStream.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpContentStream.cs index 4dc8fa1b3540e3..0c40bdb17a3179 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpContentStream.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpContentStream.cs @@ -5,7 +5,7 @@ namespace System.Net.Http { internal abstract class HttpContentStream : HttpBaseStream { - protected HttpConnection? _connection; + protected internal HttpConnection? _connection; public HttpContentStream(HttpConnection connection) { diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs index 5d4b4846a37ebd..961f6ff614892f 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs @@ -53,6 +53,10 @@ internal override async ValueTask SendAsync(HttpRequestMess // Clear the authorization header. request.Headers.Authorization = null; + if (HttpTelemetry.Log.IsEnabled()) + { + HttpTelemetry.Log.Redirect(redirectUri.AbsoluteUri); + } if (NetEventSource.Log.IsEnabled()) { Trace($"Redirecting from {request.RequestUri} to {redirectUri} in response to status code {(int)response.StatusCode} '{response.StatusCode}'.", request.GetHashCode()); diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 4f4cf14d47e6cb..82fac90c58f020 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -69,11 +69,13 @@ public void EventSource_SuccessfulRequest_LogsStartStop(string testMethod) bool buffersResponse = false; var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { await GetFactoryForVersion(version).CreateClientAndServerAsync( async uri => { + expectedUri = uri; using HttpClientHandler handler = CreateHttpClientHandler(version); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -177,7 +179,7 @@ await server.AcceptConnectionAsync(async connection => ValidateStartFailedStopEvents(events, version); - ValidateConnectionEstablishedClosed(events, version); + ValidateConnectionEstablishedClosed(events, version, expectedUri); ValidateRequestResponseStartStopEvents( events, @@ -207,6 +209,7 @@ public void EventSource_UnsuccessfulRequest_LogsStartFailedStop(string testMetho listener.AddActivityTracking(); var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { var semaphore = new SemaphoreSlim(0, 1); @@ -215,6 +218,7 @@ await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), asyn await GetFactoryForVersion(version).CreateClientAndServerAsync( async uri => { + expectedUri = uri; using HttpClientHandler handler = CreateHttpClientHandler(version); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -286,7 +290,7 @@ await server.AcceptConnectionAsync(async connection => ValidateStartFailedStopEvents(events, version, shouldHaveFailures: true); - ValidateConnectionEstablishedClosed(events, version); + ValidateConnectionEstablishedClosed(events, version, expectedUri); ValidateEventCounters(events, requestCount: 1, shouldHaveFailures: true, versionMajor: version.Major); }, UseVersion.ToString(), testMethod).Dispose(); @@ -318,11 +322,13 @@ public void EventSource_SendingRequestContent_LogsRequestContentStartStop(string listener.AddActivityTracking(); var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { await GetFactoryForVersion(version).CreateClientAndServerAsync( async uri => { + expectedUri = uri; using HttpClientHandler handler = CreateHttpClientHandler(version); using HttpClient client = CreateHttpClient(handler, useVersionString); using var invoker = new HttpMessageInvoker(handler); @@ -381,7 +387,7 @@ await server.AcceptConnectionAsync(async connection => ValidateStartFailedStopEvents(events, version); - ValidateConnectionEstablishedClosed(events, version); + ValidateConnectionEstablishedClosed(events, version, expectedUri); ValidateRequestResponseStartStopEvents( events, @@ -449,32 +455,57 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE } } - private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, int count = 1) + // The validation asssumes that the connection id's are in range 0..(connectionCount-1) + protected static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, Uri uri, int connectionCount = 1) { EventWrittenEventArgs[] connectionsEstablished = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionEstablished").ToArray(); - Assert.Equal(count, connectionsEstablished.Length); + Assert.Equal(connectionCount, connectionsEstablished.Length); + HashSet connectionIds = new HashSet(); foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { - Assert.Equal(2, connectionEstablished.Payload.Count); + Assert.Equal(7, connectionEstablished.Payload.Count); + Assert.Equal(new[] { "versionMajor", "versionMinor", "connectionId", "scheme", "host", "port", "remoteAddress" }, connectionEstablished.PayloadNames); Assert.Equal(version.Major, (byte)connectionEstablished.Payload[0]); Assert.Equal(version.Minor, (byte)connectionEstablished.Payload[1]); + long connectionId = (long)connectionEstablished.Payload[2]; + connectionIds.Add(connectionId); + + Assert.Equal(uri.Scheme, (string)connectionEstablished.Payload[3]); + Assert.Equal(uri.Host, (string)connectionEstablished.Payload[4]); + Assert.Equal(uri.Port, (int)connectionEstablished.Payload[5]); + + IPAddress ip = IPAddress.Parse((string)connectionEstablished.Payload[6]); + Assert.True(ip.Equals(IPAddress.Loopback.MapToIPv6()) || + ip.Equals(IPAddress.Loopback) || + ip.Equals(IPAddress.IPv6Loopback)); } + Assert.True(connectionIds.SetEquals(Enumerable.Range(0, connectionCount).Select(i => (long)i)), "ConnectionEstablished has logged an unexpected connectionId."); EventWrittenEventArgs[] connectionsClosed = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionClosed").ToArray(); - Assert.Equal(count, connectionsClosed.Length); + Assert.Equal(connectionCount, connectionsClosed.Length); foreach (EventWrittenEventArgs connectionClosed in connectionsClosed) { - Assert.Equal(2, connectionClosed.Payload.Count); + Assert.Equal(3, connectionClosed.Payload.Count); + Assert.Equal(new[] { "versionMajor", "versionMinor", "connectionId" }, connectionClosed.PayloadNames); Assert.Equal(version.Major, (byte)connectionClosed.Payload[0]); Assert.Equal(version.Minor, (byte)connectionClosed.Payload[1]); + long connectionId = (long)connectionClosed.Payload[2]; + Assert.True(connectionIds.Remove(connectionId), $"ConnectionClosed has logged an unexpected connectionId={connectionId}"); } + Assert.Empty(connectionIds); } - private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, int? requestContentLength, int? responseContentLength, int count) + private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, int? requestContentLength, int? responseContentLength, int count, long connectionId = 0) { (EventWrittenEventArgs Event, Guid ActivityId)[] requestHeadersStarts = events.Where(e => e.Event.EventName == "RequestHeadersStart").ToArray(); Assert.Equal(count, requestHeadersStarts.Length); - Assert.All(requestHeadersStarts, r => Assert.Empty(r.Event.Payload)); + Assert.All(requestHeadersStarts, r => + { + EventWrittenEventArgs e = r.Event; + Assert.Equal(1, e.Payload.Count); + Assert.Equal("connectionId", e.PayloadNames.Single()); + Assert.Equal(connectionId, (long)e.Payload[0]); + }); (EventWrittenEventArgs Event, Guid ActivityId)[] requestHeadersStops = events.Where(e => e.Event.EventName == "RequestHeadersStop").ToArray(); Assert.Equal(count, requestHeadersStops.Length); @@ -643,6 +674,7 @@ public void EventSource_ConnectionPoolAtMaxConnections_LogsRequestLeftQueue() listener.AddActivityTracking(); var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => { var firstRequestReceived = new SemaphoreSlim(0, 1); @@ -652,6 +684,7 @@ await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), asyn await GetFactoryForVersion(version).CreateClientAndServerAsync( async uri => { + expectedUri = uri; using HttpClientHandler handler = CreateHttpClientHandler(version, allowAllCertificates: true); using HttpClient client = CreateHttpClient(handler, useVersionString); @@ -715,7 +748,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( ValidateStartFailedStopEvents(events, version, count: 3); - ValidateConnectionEstablishedClosed(events, version); + ValidateConnectionEstablishedClosed(events, version, expectedUri); var requestLeftQueueEvents = events.Where(e => e.Event.EventName == "RequestLeftQueue"); var (minCount, maxCount) = version.Major switch @@ -744,7 +777,102 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( }, UseVersion.ToString()).Dispose(); } - private static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) + [OuterLoop] + [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + public void EventSource_Redirect_LogsRedirect() + { + RemoteExecutor.Invoke(static async (string useVersionString) => + { + Version version = Version.Parse(useVersionString); + + using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); + listener.AddActivityTracking(); + var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; + + await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => + { + await GetFactoryForVersion(version).CreateServerAsync((originalServer, originalUri) => + { + return GetFactoryForVersion(version).CreateServerAsync(async (redirectServer, redirectUri) => + { + expectedUri = redirectUri; + using HttpClient client = CreateHttpClient(useVersionString); + + using HttpRequestMessage request = new(HttpMethod.Get, originalUri) { Version = version }; + + Task clientTask = client.SendAsync(request); + Task serverTask = originalServer.HandleRequestAsync(HttpStatusCode.Redirect, new[] { new HttpHeaderData("Location", redirectUri.AbsoluteUri) }); + + await Task.WhenAny(clientTask, serverTask); + Assert.False(clientTask.IsCompleted, $"{clientTask.Status}: {clientTask.Exception}"); + await serverTask; + + serverTask = redirectServer.HandleRequestAsync(); + await TestHelper.WhenAllCompletedOrAnyFailed(clientTask, serverTask); + await clientTask; + }); + }); + + await WaitForEventCountersAsync(events); + }); + + EventWrittenEventArgs redirectEvent = events.Where(e => e.Event.EventName == "Redirect").Single().Event; + Assert.Equal(1, redirectEvent.Payload.Count); + Assert.Equal(expectedUri.ToString(), (string)redirectEvent.Payload[0]); + Assert.Equal("redirectUri", redirectEvent.PayloadNames[0]); + }, UseVersion.ToString()).Dispose(); + } + + public static bool SupportsRemoteExecutorAndAlpn = RemoteExecutor.IsSupported && PlatformDetection.SupportsAlpn; + + [OuterLoop] + [ConditionalTheory(nameof(SupportsRemoteExecutorAndAlpn))] + [InlineData(false)] + [InlineData(true)] + public void EventSource_Proxy_LogsIPAddress(bool useSsl) + { + if (UseVersion.Major == 3) + { + return; + } + + RemoteExecutor.Invoke(static async (string useVersionString, string useSslString) => + { + using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); + listener.AddActivityTracking(); + var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + + await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => + { + using LoopbackProxyServer proxyServer = LoopbackProxyServer.Create(); + + await LoopbackServer.CreateClientAndServerAsync(async uri => + { + using (HttpClientHandler handler = CreateHttpClientHandler(useVersionString)) + using (HttpClient client = CreateHttpClient(handler, useVersionString)) + { + handler.Proxy = new WebProxy(proxyServer.Uri); + await client.GetAsync(uri); + } + }, server => server.HandleRequestAsync(), options: new LoopbackServer.Options() { UseSsl = bool.Parse(useSslString) }); + + await WaitForEventCountersAsync(events); + }); + + EventWrittenEventArgs[] connectionsEstablishedEvents = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionEstablished").ToArray(); + + foreach (EventWrittenEventArgs e in connectionsEstablishedEvents) + { + IPAddress ip = IPAddress.Parse((string)e.Payload[6]); + Assert.True(ip.Equals(IPAddress.Loopback.MapToIPv6()) || + ip.Equals(IPAddress.Loopback) || + ip.Equals(IPAddress.IPv6Loopback)); + } + }, UseVersion.ToString(), useSsl.ToString()).Dispose(); + } + + protected static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) { DateTime startTime = DateTime.UtcNow; int startCount = events.Count; @@ -772,6 +900,74 @@ static bool IsRequestsStartedEventCounter(EventWrittenEventArgs e) public sealed class TelemetryTest_Http11 : TelemetryTest { public TelemetryTest_Http11(ITestOutputHelper output) : base(output) { } + + [OuterLoop] + [ActiveIssue("https://github.com/dotnet/runtime/issues/89035", TestPlatforms.OSX)] + [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + public void EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest() + { + RemoteExecutor.Invoke(async () => + { + TimeSpan timeout = TimeSpan.FromSeconds(60); + const int NumParallelRequests = 4; + + using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); + listener.AddActivityTracking(); + + var events = new ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)>(); + Uri expectedUri = null; + await listener.RunWithCallbackAsync(e => events.Enqueue((e, e.ActivityId)), async () => + { + await Http11LoopbackServerFactory.Singleton.CreateClientAndServerAsync(async uri => + { + expectedUri = uri; + using HttpClient client = CreateHttpClient(HttpVersion.Version11.ToString()); + + Task[] responseTasks = Enumerable.Repeat(uri, NumParallelRequests) + .Select(_ => client.GetAsync(uri)) + .ToArray(); + await Task.WhenAll(responseTasks).WaitAsync(timeout); + }, async server => + { + ManualResetEventSlim allConnectionsOpen = new(false); + int connectionCounter = 0; + + Task[] parallelConnectionTasks = Enumerable.Repeat(server, NumParallelRequests) + .Select(_ => server.AcceptConnectionAsync(HandleConnectionAsync)) + .ToArray(); + + await Task.WhenAll(parallelConnectionTasks); + + async Task HandleConnectionAsync(GenericLoopbackConnection connection) + { + if (Interlocked.Increment(ref connectionCounter) == NumParallelRequests) + { + allConnectionsOpen.Set(); + } + await connection.ReadRequestDataAsync().WaitAsync(timeout); + allConnectionsOpen.Wait(timeout); + await connection.SendResponseAsync(HttpStatusCode.OK); + } + }); + await WaitForEventCountersAsync(events); + }); + + Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself + + ValidateConnectionEstablishedClosed(events, HttpVersion.Version11, expectedUri, NumParallelRequests); + + EventWrittenEventArgs[] requestHeadersStart = events.Select(e => e.Event).Where(e => e.EventName == "RequestHeadersStart").ToArray(); + Assert.Equal(NumParallelRequests, requestHeadersStart.Length); + HashSet connectionIds = new(Enumerable.Range(0, NumParallelRequests).Select(i => (long)i)); + foreach (EventWrittenEventArgs e in requestHeadersStart) + { + long connectionId = (long)e.Payload.Single(); + Assert.Equal("connectionId", e.PayloadNames.Single()); + Assert.True(connectionIds.Remove(connectionId), $"RequestHeadersStart has logged an unexpected connectionId={connectionId}."); + } + Assert.Empty(connectionIds); + }).Dispose(); + } } public sealed class TelemetryTest_Http20 : TelemetryTest