From 4409013d8200bed380e579649a58c43815882cf5 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 10 Jul 2023 23:24:18 +0200 Subject: [PATCH 01/16] introduce & log connectionId --- .../src/System/Net/Http/HttpTelemetry.cs | 41 +++++++++++-------- .../SocketsHttpHandler/Http2Connection.cs | 4 +- .../SocketsHttpHandler/Http3Connection.cs | 4 +- .../Http/SocketsHttpHandler/HttpConnection.cs | 4 +- .../SocketsHttpHandler/HttpConnectionBase.cs | 7 +++- .../tests/FunctionalTests/TelemetryTest.cs | 12 +++--- 6 files changed, 41 insertions(+), 31 deletions(-) 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..bdedb28f201b12 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 @@ -91,15 +91,15 @@ private void RequestFailed(string exceptionMessage) } [Event(4, Level = EventLevel.Informational)] - private void ConnectionEstablished(byte versionMajor, byte versionMinor) + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId) { - WriteEvent(eventId: 4, versionMajor, versionMinor); + WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId); } [Event(5, Level = EventLevel.Informational)] - private void ConnectionClosed(byte versionMajor, byte versionMinor) + 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)] @@ -163,48 +163,48 @@ private void RequestFailedDetailed(string exception) } [NonEvent] - public void Http11ConnectionEstablished() + public void Http11ConnectionEstablished(long connectionId) { Interlocked.Increment(ref _openedHttp11Connections); - ConnectionEstablished(versionMajor: 1, versionMinor: 1); + ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId); } [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) { Interlocked.Increment(ref _openedHttp20Connections); - ConnectionEstablished(versionMajor: 2, versionMinor: 0); + ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId); } [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) { Interlocked.Increment(ref _openedHttp30Connections); - ConnectionEstablished(versionMajor: 3, versionMinor: 0); + ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId); } [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 +293,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 +308,11 @@ 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); } 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 b2c592a0c63b75..52f71eed5df40b 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 @@ -179,7 +179,7 @@ public Http2Connection(HttpConnectionPool pool, Stream stream) if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http20ConnectionEstablished(); + HttpTelemetry.Log.Http20ConnectionEstablished(_id); _markedByTelemetryStatus = TelemetryStatus_Opened; } @@ -1898,7 +1898,7 @@ private void FinalTeardown() { if (Interlocked.Exchange(ref _markedByTelemetryStatus, TelemetryStatus_Closed) == TelemetryStatus_Opened) { - HttpTelemetry.Log.Http20ConnectionClosed(); + HttpTelemetry.Log.Http20ConnectionClosed(_id); } } } 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 ead8e5e06123b2..3034b6cd791b29 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 @@ -95,7 +95,7 @@ public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAutho if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http30ConnectionEstablished(); + HttpTelemetry.Log.Http30ConnectionEstablished(_id); _markedByTelemetryStatus = TelemetryStatus_Opened; } @@ -172,7 +172,7 @@ private void CheckForShutdown() { if (Interlocked.Exchange(ref _markedByTelemetryStatus, TelemetryStatus_Closed) == TelemetryStatus_Opened) { - HttpTelemetry.Log.Http30ConnectionClosed(); + HttpTelemetry.Log.Http30ConnectionClosed(_id); } } } 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 d79d7233f39078..7cd2394bb0fd54 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 @@ -93,7 +93,7 @@ public HttpConnection( if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http11ConnectionEstablished(); + HttpTelemetry.Log.Http11ConnectionEstablished(_id); _disposed = Status_NotDisposedAndTrackedByTelemetry; } @@ -116,7 +116,7 @@ private void Dispose(bool disposing) // Only decrement the connection count if we counted this connection if (HttpTelemetry.Log.IsEnabled() && previousValue == Status_NotDisposedAndTrackedByTelemetry) { - HttpTelemetry.Log.Http11ConnectionClosed(); + HttpTelemetry.Log.Http11ConnectionClosed(_id); } if (!_detachedFromPool) 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 ee85e1d277df3f..95d3e1bac51567 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 @@ -15,6 +15,9 @@ namespace System.Net.Http { internal abstract class HttpConnectionBase : IDisposable, IHttpTrace { + private static long s_connectionCounter = -1; + protected readonly long _id = Interlocked.Increment(ref s_connectionCounter); + /// Cached string for the last Date header received on this connection. private string? _lastDateHeaderValue; /// Cached string for the last Server header received on this connection. @@ -47,7 +50,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}, " + @@ -56,7 +59,7 @@ protected void TraceConnection(Stream stream) } else { - Trace($"{this}"); + Trace($"{this}. Id:{_id}"); } } diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 4f4cf14d47e6cb..f1d242183aaadc 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -449,24 +449,26 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE } } - private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, int count = 1) + private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, long connectionId = 0) { EventWrittenEventArgs[] connectionsEstablished = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionEstablished").ToArray(); - Assert.Equal(count, connectionsEstablished.Length); + Assert.Equal(1, connectionsEstablished.Length); foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { - Assert.Equal(2, connectionEstablished.Payload.Count); + Assert.Equal(3, connectionEstablished.Payload.Count); Assert.Equal(version.Major, (byte)connectionEstablished.Payload[0]); Assert.Equal(version.Minor, (byte)connectionEstablished.Payload[1]); + Assert.Equal(connectionId, (long)connectionEstablished.Payload[2]); } EventWrittenEventArgs[] connectionsClosed = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionClosed").ToArray(); - Assert.Equal(count, connectionsClosed.Length); + Assert.Equal(1, connectionsClosed.Length); foreach (EventWrittenEventArgs connectionClosed in connectionsClosed) { - Assert.Equal(2, connectionClosed.Payload.Count); + Assert.Equal(3, connectionClosed.Payload.Count); Assert.Equal(version.Major, (byte)connectionClosed.Payload[0]); Assert.Equal(version.Minor, (byte)connectionClosed.Payload[1]); + Assert.Equal(connectionId, (long)connectionClosed.Payload[2]); } } From e8dfe2b8ae83e38776c53644a4c2df2e5de66f30 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Wed, 12 Jul 2023 23:17:06 +0200 Subject: [PATCH 02/16] ConnectionEstablished: log more --- .../src/System/Net/Http/HttpTelemetry.cs | 78 +++++++++++++++++-- .../SocketsHttpHandler/Http2Connection.cs | 4 +- .../SocketsHttpHandler/Http3Connection.cs | 4 +- .../Http/SocketsHttpHandler/HttpConnection.cs | 6 +- .../SocketsHttpHandler/HttpConnectionPool.cs | 38 +++++---- .../tests/FunctionalTests/TelemetryTest.cs | 28 +++++-- 6 files changed, 123 insertions(+), 35 deletions(-) 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 bdedb28f201b12..4e12f4bef22668 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,10 +90,17 @@ private void RequestFailed(string exceptionMessage) WriteEvent(eventId: 3, exceptionMessage); } + [NonEvent] + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, Uri uri, EndPoint? remoteEndPoint) + { + string? remoteAddress = (remoteEndPoint as IPEndPoint)?.Address?.ToString(); + ConnectionEstablished(versionMajor, versionMinor, connectionId, uri.Scheme, uri.Host, uri.Port, remoteAddress); + } + [Event(4, Level = EventLevel.Informational)] - private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId) + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress) { - WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId); + WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); } [Event(5, Level = EventLevel.Informational)] @@ -163,10 +170,10 @@ private void RequestFailedDetailed(string exception) } [NonEvent] - public void Http11ConnectionEstablished(long connectionId) + public void Http11ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp11Connections); - ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId); + ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, uri, remoteEndPoint); } [NonEvent] @@ -178,10 +185,10 @@ public void Http11ConnectionClosed(long connectionId) } [NonEvent] - public void Http20ConnectionEstablished(long connectionId) + public void Http20ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp20Connections); - ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId); + ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, uri, remoteEndPoint); } [NonEvent] @@ -193,10 +200,10 @@ public void Http20ConnectionClosed(long connectionId) } [NonEvent] - public void Http30ConnectionEstablished(long connectionId) + public void Http30ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp30Connections); - ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId); + ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, uri, remoteEndPoint); } [NonEvent] @@ -316,5 +323,60 @@ private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3) 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 ??= ""; + 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 52f71eed5df40b..1da1937f463029 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 @@ -137,7 +137,7 @@ internal enum KeepAliveState private long _keepAlivePingTimeoutTimestamp; private volatile KeepAliveState _keepAliveState; - public Http2Connection(HttpConnectionPool pool, Stream stream) + public Http2Connection(HttpConnectionPool pool, Stream stream, Uri requestUri, EndPoint? remoteEndPoint) { _pool = pool; _stream = stream; @@ -179,7 +179,7 @@ public Http2Connection(HttpConnectionPool pool, Stream stream) if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http20ConnectionEstablished(_id); + HttpTelemetry.Log.Http20ConnectionEstablished(_id, requestUri, remoteEndPoint); _markedByTelemetryStatus = TelemetryStatus_Opened; } 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 3034b6cd791b29..51526150fd5f14 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 @@ -71,7 +71,7 @@ private bool ShuttingDown } } - public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAuthority authority, QuicConnection connection, bool includeAltUsedHeader) + public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAuthority authority, QuicConnection connection, Uri requestUri, bool includeAltUsedHeader) { _pool = pool; _origin = origin; @@ -95,7 +95,7 @@ public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAutho if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http30ConnectionEstablished(_id); + HttpTelemetry.Log.Http30ConnectionEstablished(_id, requestUri, connection.RemoteEndPoint); _markedByTelemetryStatus = TelemetryStatus_Opened; } 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 7cd2394bb0fd54..4dfa0c08fa69f6 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 @@ -76,7 +76,9 @@ internal sealed partial class HttpConnection : HttpConnectionBase public HttpConnection( HttpConnectionPool pool, Stream stream, - TransportContext? transportContext) + TransportContext? transportContext, + Uri requestUri, + EndPoint? remoteEndPoint) { Debug.Assert(pool != null); Debug.Assert(stream != null); @@ -93,7 +95,7 @@ public HttpConnection( if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http11ConnectionEstablished(_id); + HttpTelemetry.Log.Http11ConnectionEstablished(_id, requestUri, remoteEndPoint); _disposed = Status_NotDisposedAndTrackedByTelemetry; } 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 a460307b99c040..48d284300dda2c 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 @@ -605,7 +605,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, EndPoint? remoteEndPoint, CancellationToken cancellationToken) { if (NetEventSource.Log.IsEnabled()) Trace("Server does not support HTTP2; disabling HTTP2 use and proceeding with HTTP/1.1 connection"); @@ -662,7 +662,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) { @@ -694,7 +694,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, EndPoint? remoteEndPoint) = await ConnectAsync(queueItem.Request, true, cts.Token).ConfigureAwait(false); if (IsSecure) { @@ -711,19 +711,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) @@ -956,7 +956,8 @@ private async ValueTask GetHttp3ConnectionAsync(HttpRequestMess } #endif // if the authority was sent as an option through alt-svc then include alt-used header - http3Connection = new Http3Connection(this, _originAuthority, authority, quicConnection, includeAltUsedHeader: _http3Authority == authority); + Debug.Assert(request.RequestUri != null); + http3Connection = new Http3Connection(this, _originAuthority, authority, quicConnection, request.RequestUri, includeAltUsedHeader: _http3Authority == authority); _http3Connection = http3Connection; if (NetEventSource.Log.IsEnabled()) @@ -1535,9 +1536,10 @@ 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?, EndPoint?)> ConnectAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) { Stream? stream = null; + EndPoint? remoteEndPoint = null; switch (_kind) { case HttpConnectionKind.Http: @@ -1545,6 +1547,7 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.ProxyConnect: Debug.Assert(_originAuthority != null); stream = await ConnectToTcpHostAsync(_originAuthority.IdnHost, _originAuthority.Port, request, async, cancellationToken).ConfigureAwait(false); + remoteEndPoint = GetRemoteEndPoint(stream); if (_kind == HttpConnectionKind.ProxyConnect && _sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1553,6 +1556,7 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.Proxy: stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false); + remoteEndPoint = GetRemoteEndPoint(stream); if (_sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1591,7 +1595,9 @@ public ValueTask SendAsync(HttpRequestMessage request, bool stream = sslStream; } - return (stream, transportContext); + static EndPoint? GetRemoteEndPoint(Stream stream) => (stream as NetworkStream)?.Socket?.RemoteEndPoint; + + return (stream, transportContext, remoteEndPoint); } private async ValueTask ConnectToTcpHostAsync(string host, int port, HttpRequestMessage initialRequest, bool async, CancellationToken cancellationToken) @@ -1657,8 +1663,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, EndPoint? remoteEndPoint) = await ConnectAsync(request, async, cancellationToken).ConfigureAwait(false); + return await ConstructHttp11ConnectionAsync(async, stream, transportContext, request, remoteEndPoint, cancellationToken).ConfigureAwait(false); } private SslClientAuthenticationOptions GetSslOptionsForRequest(HttpRequestMessage request) @@ -1721,17 +1727,19 @@ 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, EndPoint? remoteEndPoint, CancellationToken cancellationToken) { Stream newStream = await ApplyPlaintextFilterAsync(async, stream, HttpVersion.Version11, request, cancellationToken).ConfigureAwait(false); - return new HttpConnection(this, newStream, transportContext); + Debug.Assert(request.RequestUri != null); + return new HttpConnection(this, newStream, transportContext, request.RequestUri, remoteEndPoint); } - private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, CancellationToken cancellationToken) + private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, EndPoint? remoteEndPoint, CancellationToken cancellationToken) { stream = await ApplyPlaintextFilterAsync(async: true, stream, HttpVersion.Version20, request, cancellationToken).ConfigureAwait(false); - Http2Connection http2Connection = new Http2Connection(this, stream); + Debug.Assert(request.RequestUri != null); + Http2Connection http2Connection = new Http2Connection(this, stream, request.RequestUri, remoteEndPoint); try { await http2Connection.SetupAsync(cancellationToken).ConfigureAwait(false); diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index f1d242183aaadc..c529be0af7ab34 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,16 +455,24 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE } } - private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, long connectionId = 0) + private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, Uri uri, long connectionId = 0) { EventWrittenEventArgs[] connectionsEstablished = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionEstablished").ToArray(); Assert.Equal(1, connectionsEstablished.Length); foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { - Assert.Equal(3, connectionEstablished.Payload.Count); + Assert.Equal(7, connectionEstablished.Payload.Count); Assert.Equal(version.Major, (byte)connectionEstablished.Payload[0]); Assert.Equal(version.Minor, (byte)connectionEstablished.Payload[1]); Assert.Equal(connectionId, (long)connectionEstablished.Payload[2]); + 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)); } EventWrittenEventArgs[] connectionsClosed = events.Select(e => e.Event).Where(e => e.EventName == "ConnectionClosed").ToArray(); @@ -645,6 +659,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); @@ -654,6 +669,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); @@ -717,7 +733,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 From 2c5136c840c06cb4c74b8e23037f32b040964178 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Thu, 13 Jul 2023 03:46:19 +0200 Subject: [PATCH 03/16] RequestHeadersStart: long PaddedFlag also: pass around IPEndPoint instead of EndPoint --- .../src/System/Net/Http/HttpTelemetry.cs | 14 +++++----- .../SocketsHttpHandler/Http2Connection.cs | 8 +++--- .../SocketsHttpHandler/Http3Connection.cs | 4 +-- .../SocketsHttpHandler/Http3RequestStream.cs | 2 +- .../Http/SocketsHttpHandler/HttpConnection.cs | 8 +++--- .../SocketsHttpHandler/HttpConnectionBase.cs | 7 ++--- .../SocketsHttpHandler/HttpConnectionPool.cs | 26 ++++++++++++------- .../tests/FunctionalTests/TelemetryTest.cs | 9 +++++-- 8 files changed, 45 insertions(+), 33 deletions(-) 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 4e12f4bef22668..c70c1c2ae6d99e 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 @@ -91,9 +91,9 @@ private void RequestFailed(string exceptionMessage) } [NonEvent] - private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, Uri uri, EndPoint? remoteEndPoint) + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, Uri uri, IPEndPoint? remoteEndPoint) { - string? remoteAddress = (remoteEndPoint as IPEndPoint)?.Address?.ToString(); + string? remoteAddress = remoteEndPoint?.Address?.ToString(); ConnectionEstablished(versionMajor, versionMinor, connectionId, uri.Scheme, uri.Host, uri.Port, remoteAddress); } @@ -116,9 +116,9 @@ private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor, } [Event(7, Level = EventLevel.Informational)] - public void RequestHeadersStart() + public void RequestHeadersStart(long connectionId) { - WriteEvent(eventId: 7); + WriteEvent(eventId: 7, connectionId); } [Event(8, Level = EventLevel.Informational)] @@ -170,7 +170,7 @@ private void RequestFailedDetailed(string exception) } [NonEvent] - public void Http11ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) + public void Http11ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp11Connections); ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, uri, remoteEndPoint); @@ -185,7 +185,7 @@ public void Http11ConnectionClosed(long connectionId) } [NonEvent] - public void Http20ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) + public void Http20ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp20Connections); ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, uri, remoteEndPoint); @@ -200,7 +200,7 @@ public void Http20ConnectionClosed(long connectionId) } [NonEvent] - public void Http30ConnectionEstablished(long connectionId, Uri uri, EndPoint? remoteEndPoint) + public void Http30ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp30Connections); ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, uri, remoteEndPoint); 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 1da1937f463029..c0c17d71c43cad 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 @@ -137,7 +137,7 @@ internal enum KeepAliveState private long _keepAlivePingTimeoutTimestamp; private volatile KeepAliveState _keepAliveState; - public Http2Connection(HttpConnectionPool pool, Stream stream, Uri requestUri, EndPoint? remoteEndPoint) + public Http2Connection(HttpConnectionPool pool, Stream stream, Uri requestUri, IPEndPoint? remoteEndPoint) { _pool = pool; _stream = stream; @@ -179,7 +179,7 @@ public Http2Connection(HttpConnectionPool pool, Stream stream, Uri requestUri, E if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http20ConnectionEstablished(_id, requestUri, remoteEndPoint); + HttpTelemetry.Log.Http20ConnectionEstablished(Id, requestUri, remoteEndPoint); _markedByTelemetryStatus = TelemetryStatus_Opened; } @@ -1662,7 +1662,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. @@ -1898,7 +1898,7 @@ private void FinalTeardown() { if (Interlocked.Exchange(ref _markedByTelemetryStatus, TelemetryStatus_Closed) == TelemetryStatus_Opened) { - HttpTelemetry.Log.Http20ConnectionClosed(_id); + HttpTelemetry.Log.Http20ConnectionClosed(Id); } } } 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 51526150fd5f14..38a70afb5f1647 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 @@ -95,7 +95,7 @@ public Http3Connection(HttpConnectionPool pool, HttpAuthority? origin, HttpAutho if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http30ConnectionEstablished(_id, requestUri, connection.RemoteEndPoint); + HttpTelemetry.Log.Http30ConnectionEstablished(Id, requestUri, connection.RemoteEndPoint); _markedByTelemetryStatus = TelemetryStatus_Opened; } @@ -172,7 +172,7 @@ private void CheckForShutdown() { if (Interlocked.Exchange(ref _markedByTelemetryStatus, TelemetryStatus_Closed) == TelemetryStatus_Opened) { - HttpTelemetry.Log.Http30ConnectionClosed(_id); + HttpTelemetry.Log.Http30ConnectionClosed(Id); } } } 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 4dfa0c08fa69f6..140b060ad6383f 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 @@ -78,7 +78,7 @@ public HttpConnection( Stream stream, TransportContext? transportContext, Uri requestUri, - EndPoint? remoteEndPoint) + IPEndPoint? remoteEndPoint) { Debug.Assert(pool != null); Debug.Assert(stream != null); @@ -95,7 +95,7 @@ public HttpConnection( if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Http11ConnectionEstablished(_id, requestUri, remoteEndPoint); + HttpTelemetry.Log.Http11ConnectionEstablished(Id, requestUri, remoteEndPoint); _disposed = Status_NotDisposedAndTrackedByTelemetry; } @@ -118,7 +118,7 @@ private void Dispose(bool disposing) // Only decrement the connection count if we counted this connection if (HttpTelemetry.Log.IsEnabled() && previousValue == Status_NotDisposedAndTrackedByTelemetry) { - HttpTelemetry.Log.Http11ConnectionClosed(_id); + HttpTelemetry.Log.Http11ConnectionClosed(Id); } if (!_detachedFromPool) @@ -533,7 +533,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 95d3e1bac51567..61b090029112fa 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,13 +16,14 @@ namespace System.Net.Http internal abstract class HttpConnectionBase : IDisposable, IHttpTrace { private static long s_connectionCounter = -1; - protected readonly long _id = Interlocked.Increment(ref s_connectionCounter); /// Cached string for the last Date header received on this connection. private string? _lastDateHeaderValue; /// Cached string for the last Server header received on this connection. private string? _lastServerHeaderValue; + internal long Id { get; } = Interlocked.Increment(ref s_connectionCounter); + /// Uses , but first special-cases several known headers for which we can use caching. public string GetResponseHeaderValueWithCaching(HeaderDescriptor descriptor, ReadOnlySpan value, Encoding? valueEncoding) { @@ -50,7 +51,7 @@ protected void TraceConnection(Stream stream) if (stream is SslStream sslStream) { Trace( - $"{this}. Id:{_id}, " + + $"{this}. Id:{Id}, " + $"SslProtocol:{sslStream.SslProtocol}, NegotiatedApplicationProtocol:{sslStream.NegotiatedApplicationProtocol}, " + $"NegotiatedCipherSuite:{sslStream.NegotiatedCipherSuite}, CipherAlgorithm:{sslStream.CipherAlgorithm}, CipherStrength:{sslStream.CipherStrength}, " + $"HashAlgorithm:{sslStream.HashAlgorithm}, HashStrength:{sslStream.HashStrength}, " + @@ -59,7 +60,7 @@ protected void TraceConnection(Stream stream) } else { - Trace($"{this}. Id:{_id}"); + 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 48d284300dda2c..9399f37c42ed99 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 @@ -605,7 +605,7 @@ private bool TryGetPooledHttp11Connection(HttpRequestMessage request, bool async } } - private async Task HandleHttp11Downgrade(HttpRequestMessage request, Stream stream, TransportContext? transportContext, EndPoint? remoteEndPoint, 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"); @@ -694,7 +694,7 @@ private async Task AddHttp2ConnectionAsync(RequestQueue.QueueI waiter.ConnectionCancellationTokenSource = cts; try { - (Stream stream, TransportContext? transportContext, EndPoint? remoteEndPoint) = 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) { @@ -1536,10 +1536,10 @@ public ValueTask SendAsync(HttpRequestMessage request, bool private CancellationTokenSource GetConnectTimeoutCancellationTokenSource() => new CancellationTokenSource(Settings._connectTimeout); - private async ValueTask<(Stream, TransportContext?, EndPoint?)> ConnectAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) + private async ValueTask<(Stream, TransportContext?, IPEndPoint?)> ConnectAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) { Stream? stream = null; - EndPoint? remoteEndPoint = null; + IPEndPoint? remoteEndPoint = null; switch (_kind) { case HttpConnectionKind.Http: @@ -1547,7 +1547,10 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.ProxyConnect: Debug.Assert(_originAuthority != null); stream = await ConnectToTcpHostAsync(_originAuthority.IdnHost, _originAuthority.Port, request, async, cancellationToken).ConfigureAwait(false); - remoteEndPoint = GetRemoteEndPoint(stream); + if (HttpTelemetry.Log.IsEnabled()) + { + remoteEndPoint = GetRemoteEndPoint(stream); + } if (_kind == HttpConnectionKind.ProxyConnect && _sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1556,7 +1559,10 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.Proxy: stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false); - remoteEndPoint = GetRemoteEndPoint(stream); + if (HttpTelemetry.Log.IsEnabled()) + { + remoteEndPoint = GetRemoteEndPoint(stream); + } if (_sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1595,7 +1601,7 @@ public ValueTask SendAsync(HttpRequestMessage request, bool stream = sslStream; } - static EndPoint? GetRemoteEndPoint(Stream stream) => (stream as NetworkStream)?.Socket?.RemoteEndPoint; + static IPEndPoint? GetRemoteEndPoint(Stream stream) => (stream as NetworkStream)?.Socket?.RemoteEndPoint as IPEndPoint; return (stream, transportContext, remoteEndPoint); } @@ -1663,7 +1669,7 @@ private async ValueTask ConnectToTcpHostAsync(string host, int port, Htt internal async ValueTask CreateHttp11ConnectionAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken) { - (Stream stream, TransportContext? transportContext, EndPoint? remoteEndPoint) = await ConnectAsync(request, async, 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); } @@ -1727,14 +1733,14 @@ private async ValueTask ApplyPlaintextFilterAsync(bool async, Stream str return newStream; } - private async ValueTask ConstructHttp11ConnectionAsync(bool async, Stream stream, TransportContext? transportContext, HttpRequestMessage request, EndPoint? remoteEndPoint, 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); Debug.Assert(request.RequestUri != null); return new HttpConnection(this, newStream, transportContext, request.RequestUri, remoteEndPoint); } - private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, EndPoint? remoteEndPoint, 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); diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index c529be0af7ab34..eb51e443dfdb25 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -486,11 +486,16 @@ private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWr } } - 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, (long)e.Payload[0]); + }); (EventWrittenEventArgs Event, Guid ActivityId)[] requestHeadersStops = events.Where(e => e.Event.EventName == "RequestHeadersStop").ToArray(); Assert.Equal(count, requestHeadersStops.Length); From bb85d166e16927f3b330fafc8276d07c0c8a6d69 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Thu, 13 Jul 2023 15:30:30 +0200 Subject: [PATCH 04/16] EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest --- .../tests/FunctionalTests/TelemetryTest.cs | 85 +++++++++++++++++-- 1 file changed, 79 insertions(+), 6 deletions(-) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index eb51e443dfdb25..5d9929b90a9d2c 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -455,16 +455,20 @@ private static void ValidateStartFailedStopEvents(ConcurrentQueue<(EventWrittenE } } - private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events, Version version, Uri uri, long connectionId = 0) + // 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(1, connectionsEstablished.Length); + Assert.Equal(connectionCount, connectionsEstablished.Length); + HashSet connectionIds = new HashSet(); foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { Assert.Equal(7, connectionEstablished.Payload.Count); Assert.Equal(version.Major, (byte)connectionEstablished.Payload[0]); Assert.Equal(version.Minor, (byte)connectionEstablished.Payload[1]); - Assert.Equal(connectionId, (long)connectionEstablished.Payload[2]); + 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]); @@ -474,16 +478,19 @@ private static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(EventWr 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(1, connectionsClosed.Length); + Assert.Equal(connectionCount, connectionsClosed.Length); foreach (EventWrittenEventArgs connectionClosed in connectionsClosed) { Assert.Equal(3, connectionClosed.Payload.Count); Assert.Equal(version.Major, (byte)connectionClosed.Payload[0]); Assert.Equal(version.Minor, (byte)connectionClosed.Payload[1]); - Assert.Equal(connectionId, (long)connectionClosed.Payload[2]); + 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, long connectionId = 0) @@ -767,7 +774,7 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( }, UseVersion.ToString()).Dispose(); } - private static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) + protected static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) { DateTime startTime = DateTime.UtcNow; int startCount = events.Count; @@ -795,6 +802,72 @@ static bool IsRequestsStartedEventCounter(EventWrittenEventArgs e) public sealed class TelemetryTest_Http11 : TelemetryTest { public TelemetryTest_Http11(ITestOutputHelper output) : base(output) { } + + [OuterLoop] + [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + public void EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest() + { + RemoteExecutor.Invoke(async () => + { + TimeSpan timeout = TimeSpan.FromSeconds(10); + 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[] prallelConnectionTasks = Enumerable.Repeat(server, NumParallelRequests) + .Select(_ => server.AcceptConnectionAsync(HandleConnectionAsync)) + .ToArray(); + + await Task.WhenAll(prallelConnectionTasks); + + 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); + }).WaitAsync(timeout); + + 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[0]; + Assert.True(connectionIds.Remove(connectionId), $"RequestHeadersStart has logged an unexpected connectionId={connectionId}."); + } + Assert.Empty(connectionIds); + }).Dispose(); + } } public sealed class TelemetryTest_Http20 : TelemetryTest From cdca548863b265404914b2c8d799feacdef379a4 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Thu, 13 Jul 2023 18:55:52 +0200 Subject: [PATCH 05/16] implement Redirect(redirectUri) --- .../src/System/Net/Http/HttpTelemetry.cs | 6 +++ .../SocketsHttpHandler/RedirectHandler.cs | 4 ++ .../tests/FunctionalTests/TelemetryTest.cs | 48 ++++++++++++++++++- 3 files changed, 57 insertions(+), 1 deletion(-) 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 c70c1c2ae6d99e..85efbec56e21e6 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 @@ -169,6 +169,12 @@ 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(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) { 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..4ed5d066c5a890 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.ToString()); + } 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 5d9929b90a9d2c..a3769d9c644c30 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -774,6 +774,52 @@ await GetFactoryForVersion(version).CreateClientAndServerAsync( }, UseVersion.ToString()).Dispose(); } + [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]); + }, UseVersion.ToString()).Dispose(); + } + protected static async Task WaitForEventCountersAsync(ConcurrentQueue<(EventWrittenEventArgs Event, Guid ActivityId)> events) { DateTime startTime = DateTime.UtcNow; @@ -809,7 +855,7 @@ public void EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest() { RemoteExecutor.Invoke(async () => { - TimeSpan timeout = TimeSpan.FromSeconds(10); + TimeSpan timeout = TimeSpan.FromSeconds(30); const int NumParallelRequests = 4; using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); From 80353d0b87678d8ba0923cb261b12b04e20c5b88 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Thu, 13 Jul 2023 19:10:17 +0200 Subject: [PATCH 06/16] ready to go --- .../System.Net.Http/src/System/Net/Http/HttpTelemetry.cs | 1 + .../System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs | 2 ++ 2 files changed, 3 insertions(+) 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 85efbec56e21e6..6d6a531c7e4be6 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 @@ -336,6 +336,7 @@ private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3) 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; 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 9399f37c42ed99..9330db17ef3ed6 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 @@ -1549,6 +1549,7 @@ public ValueTask SendAsync(HttpRequestMessage request, bool stream = await ConnectToTcpHostAsync(_originAuthority.IdnHost, _originAuthority.Port, request, async, cancellationToken).ConfigureAwait(false); if (HttpTelemetry.Log.IsEnabled()) { + // remoteEndPoint is returned optionally for diagnostic purposes. remoteEndPoint = GetRemoteEndPoint(stream); } if (_kind == HttpConnectionKind.ProxyConnect && _sslOptionsProxy != null) @@ -1561,6 +1562,7 @@ public ValueTask SendAsync(HttpRequestMessage request, bool stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false); if (HttpTelemetry.Log.IsEnabled()) { + // remoteEndPoint is returned optionally for diagnostic purposes. remoteEndPoint = GetRemoteEndPoint(stream); } if (_sslOptionsProxy != null) From e4e88e2b9b671f237a77f701f2f6bd9d07a82dc2 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Thu, 13 Jul 2023 19:35:45 +0200 Subject: [PATCH 07/16] validate payload names in tests --- .../System.Net.Http/tests/FunctionalTests/TelemetryTest.cs | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index a3769d9c644c30..4e0a28d655c906 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -464,6 +464,7 @@ protected static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(Event foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { 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]; @@ -485,6 +486,7 @@ protected static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(Event foreach (EventWrittenEventArgs connectionClosed in connectionsClosed) { 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]; @@ -501,6 +503,7 @@ private static void ValidateRequestResponseStartStopEvents(ConcurrentQueue<(Even { EventWrittenEventArgs e = r.Event; Assert.Equal(1, e.Payload.Count); + Assert.Equal("connectionId", e.PayloadNames.Single()); Assert.Equal(connectionId, (long)e.Payload[0]); }); @@ -817,6 +820,7 @@ await GetFactoryForVersion(version).CreateServerAsync((originalServer, originalU 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(); } @@ -908,7 +912,8 @@ async Task HandleConnectionAsync(GenericLoopbackConnection connection) HashSet connectionIds = new(Enumerable.Range(0, NumParallelRequests).Select(i => (long)i)); foreach (EventWrittenEventArgs e in requestHeadersStart) { - long connectionId = (long)e.Payload[0]; + 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); From d6ac30fd5571ca434db0ceb16d7612ae5b3a022c Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Sun, 16 Jul 2023 16:29:25 +0200 Subject: [PATCH 08/16] adjust logic to current main, log socketaddress to metrics --- .../src/System/Net/Http/HttpTelemetry.cs | 22 +++++++++--------- .../SocketsHttpHandler/Http2Connection.cs | 6 ++--- .../SocketsHttpHandler/Http3Connection.cs | 2 +- .../Http/SocketsHttpHandler/HttpConnection.cs | 7 +++--- .../SocketsHttpHandler/HttpConnectionBase.cs | 23 +++++++++++-------- .../SocketsHttpHandler/HttpConnectionPool.cs | 22 ++++++------------ .../Metrics/ConnectionMetrics.cs | 9 +++++++- .../tests/FunctionalTests/MetricsTest.cs | 21 ++++++++++++----- .../tests/FunctionalTests/TelemetryTest.cs | 2 +- 9 files changed, 64 insertions(+), 50 deletions(-) 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 6d6a531c7e4be6..87ddb23749e99b 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 @@ -91,16 +91,16 @@ private void RequestFailed(string exceptionMessage) } [NonEvent] - private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, Uri uri, IPEndPoint? remoteEndPoint) + 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, uri.Scheme, uri.Host, uri.Port, remoteAddress); + string? socketAddress = remoteEndPoint?.Address?.ToString(); + ConnectionEstablished(versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); } [Event(4, Level = EventLevel.Informational)] - private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress) + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? socketAddress) { - WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); + WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); } [Event(5, Level = EventLevel.Informational)] @@ -176,10 +176,10 @@ public void Redirect(string redirectUri) } [NonEvent] - public void Http11ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) + public void Http11ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp11Connections); - ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, uri, remoteEndPoint); + ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] @@ -191,10 +191,10 @@ public void Http11ConnectionClosed(long connectionId) } [NonEvent] - public void Http20ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) + public void Http20ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp20Connections); - ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, uri, remoteEndPoint); + ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] @@ -206,10 +206,10 @@ public void Http20ConnectionClosed(long connectionId) } [NonEvent] - public void Http30ConnectionEstablished(long connectionId, Uri uri, IPEndPoint? remoteEndPoint) + public void Http30ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { Interlocked.Increment(ref _openedHttp30Connections); - ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, uri, remoteEndPoint); + ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint); } [NonEvent] 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/HttpConnection.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnection.cs index 036012a0cf3553..de185001a8c898 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 @@ -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 8cbe5855353f84..46f738b693b8e9 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 @@ -33,9 +33,9 @@ internal abstract class HttpConnectionBase : IDisposable, IHttpTrace /// Cached string for the last Server header received on this connection. private string? _lastServerHeaderValue; - internal long Id { get; } = Interlocked.Increment(ref s_connectionCounter); + public long Id { get; } = Interlocked.Increment(ref s_connectionCounter); - public HttpConnectionBase(HttpConnectionPool pool) + public HttpConnectionBase(HttpConnectionPool pool, IPEndPoint? remoteEndPoint) { Debug.Assert(this is HttpConnection or Http2Connection or Http3Connection); Debug.Assert(pool.Settings._metrics is not null); @@ -59,7 +59,8 @@ public HttpConnectionBase(HttpConnectionPool pool) protocol, pool.IsSecure ? "https" : "http", pool.OriginAuthority.HostValue, - port == defaultPort ? null : port); + port == defaultPort ? null : port, + remoteEndPoint?.Address?.ToString()); _connectionMetrics.ConnectionEstablished(); @@ -70,9 +71,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); } } @@ -85,9 +90,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); } } } 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 e1f1c90abccc1f..2d2fd0d05a26d2 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; @@ -955,7 +956,6 @@ private async ValueTask GetHttp3ConnectionAsync(HttpRequestMess #endif // if the authority was sent as an option through alt-svc then include alt-used header http3Connection = new Http3Connection(this, authority, quicConnection, includeAltUsedHeader: _http3Authority == authority); - http3Connection = new Http3Connection(this, _originAuthority, authority, quicConnection, request.RequestUri, includeAltUsedHeader: _http3Authority == authority); _http3Connection = http3Connection; if (NetEventSource.Log.IsEnabled()) @@ -1544,11 +1544,8 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.Https: case HttpConnectionKind.ProxyConnect: stream = await ConnectToTcpHostAsync(_originAuthority.IdnHost, _originAuthority.Port, request, async, cancellationToken).ConfigureAwait(false); - if (HttpTelemetry.Log.IsEnabled()) - { - // remoteEndPoint is returned optionally for diagnostic purposes. - remoteEndPoint = GetRemoteEndPoint(stream); - } + // 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); @@ -1557,11 +1554,8 @@ public ValueTask SendAsync(HttpRequestMessage request, bool case HttpConnectionKind.Proxy: stream = await ConnectToTcpHostAsync(_proxyUri!.IdnHost, _proxyUri.Port, request, async, cancellationToken).ConfigureAwait(false); - if (HttpTelemetry.Log.IsEnabled()) - { - // remoteEndPoint is returned optionally for diagnostic purposes. - remoteEndPoint = GetRemoteEndPoint(stream); - } + // remoteEndPoint is returned for diagnostic purposes. + remoteEndPoint = GetRemoteEndPoint(stream); if (_sslOptionsProxy != null) { stream = await ConnectHelper.EstablishSslConnectionAsync(_sslOptionsProxy, request, async, stream, cancellationToken).ConfigureAwait(false); @@ -1735,16 +1729,14 @@ private async ValueTask ApplyPlaintextFilterAsync(bool async, Stream str 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); - Debug.Assert(request.RequestUri != null); - return new HttpConnection(this, newStream, transportContext, request.RequestUri, remoteEndPoint); + return new HttpConnection(this, newStream, transportContext, remoteEndPoint); } private async ValueTask ConstructHttp2ConnectionAsync(Stream stream, HttpRequestMessage request, IPEndPoint? remoteEndPoint, CancellationToken cancellationToken) { stream = await ApplyPlaintextFilterAsync(async: true, stream, HttpVersion.Version20, request, cancellationToken).ConfigureAwait(false); - Debug.Assert(request.RequestUri != null); - Http2Connection http2Connection = new Http2Connection(this, stream, request.RequestUri, remoteEndPoint); + 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/Metrics/ConnectionMetrics.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs index d047f70766fd05..f5edf24d27712b 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs @@ -14,9 +14,10 @@ internal sealed class ConnectionMetrics private readonly object _schemeTag; private readonly object _hostTag; private readonly object? _portTag; + private readonly string? _socketAddress; private bool _currentlyIdle; - public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, string scheme, string host, int? port) + public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, string scheme, string host, int? port, string? socketAddress) { _metrics = metrics; _currentConnectionsEnabled = _metrics.CurrentConnections.Enabled; @@ -25,6 +26,7 @@ public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, str _schemeTag = scheme; _hostTag = host; _portTag = port; + _socketAddress = socketAddress; } // TagList is a huge struct, so we avoid storing it in a field to reduce the amount we allocate on the heap. @@ -41,6 +43,11 @@ private TagList GetTags() tags.Add("port", _portTag); } + if (_socketAddress is not null) + { + tags.Add("socket.address", _socketAddress); + } + return tags; } diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs index c27ce9c3ff4818..b3d15f6709c292 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs @@ -46,11 +46,20 @@ protected static void VerifyOptionalTag(KeyValuePair[] tags, } } - private static void VerifySchemeHostPortTags(KeyValuePair[] tags, Uri uri) + private static void VerifySchemeHostPortSocketAddressTags(KeyValuePair[] tags, Uri uri, bool verifySocketAddress = false) { VerifyOptionalTag(tags, "scheme", uri.Scheme); VerifyOptionalTag(tags, "host", uri.Host); VerifyOptionalTag(tags, "port", uri.Port); + + if (verifySocketAddress) + { + string socketAddress = (string)tags.Single(t => t.Key == "socket.address").Value; + IPAddress ip = IPAddress.Parse(socketAddress); + Assert.True(ip.Equals(IPAddress.Loopback.MapToIPv6()) || + ip.Equals(IPAddress.Loopback) || + ip.Equals(IPAddress.IPv6Loopback)); + } } protected static void VerifyRequestDuration(Measurement measurement, Uri uri, string? protocol, int? statusCode, string method = "GET") => @@ -60,7 +69,7 @@ protected static void VerifyRequestDuration(string instrumentName, double measur { Assert.Equal(InstrumentNames.RequestDuration, instrumentName); Assert.InRange(measurement, double.Epsilon, 60); - VerifySchemeHostPortTags(tags, uri); + VerifySchemeHostPortSocketAddressTags(tags, uri); VerifyOptionalTag(tags, "method", method); VerifyOptionalTag(tags, "protocol", protocol); VerifyOptionalTag(tags, "status-code", statusCode); @@ -73,7 +82,7 @@ protected static void VerifyCurrentRequest(string instrumentName, long measureme { Assert.Equal(InstrumentNames.CurrentRequests, instrumentName); Assert.Equal(expectedValue, measurement); - VerifySchemeHostPortTags(tags, uri); + VerifySchemeHostPortSocketAddressTags(tags, uri); } protected static void VerifyFailedRequests(Measurement measurement, long expectedValue, Uri uri, string? protocol, int? statusCode, string method = "GET") @@ -82,7 +91,7 @@ protected static void VerifyFailedRequests(Measurement measurement, long e KeyValuePair[] tags = measurement.Tags.ToArray(); - VerifySchemeHostPortTags(tags, uri); + VerifySchemeHostPortSocketAddressTags(tags, uri); Assert.Equal(method, tags.Single(t => t.Key == "method").Value); VerifyOptionalTag(tags, "protocol", protocol); @@ -93,7 +102,7 @@ protected static void VerifyConnectionCounter(string expectedName, string actual { Assert.Equal(expectedName, actualName); Assert.Equal(expectedValue, Assert.IsType(measurement)); - VerifySchemeHostPortTags(tags, uri); + VerifySchemeHostPortSocketAddressTags(tags, uri, verifySocketAddress: true); VerifyOptionalTag(tags, "protocol", protocol); } @@ -101,7 +110,7 @@ protected static void VerifyConnectionDuration(string instrumentName, double mea { Assert.InRange(measurement, double.Epsilon, 60); Assert.Equal(InstrumentNames.ConnectionDuration, instrumentName); - VerifySchemeHostPortTags(tags, uri); + VerifySchemeHostPortSocketAddressTags(tags, uri, verifySocketAddress: true); VerifyOptionalTag(tags, "protocol", protocol); } diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 4e0a28d655c906..164b976ae2e414 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -464,7 +464,7 @@ protected static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(Event foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { Assert.Equal(7, connectionEstablished.Payload.Count); - Assert.Equal(new[] { "versionMajor", "versionMinor", "connectionId", "scheme", "host", "port", "remoteAddress" }, connectionEstablished.PayloadNames); + Assert.Equal(new[] { "versionMajor", "versionMinor", "connectionId", "scheme", "host", "port", "socketAddress" }, connectionEstablished.PayloadNames); Assert.Equal(version.Major, (byte)connectionEstablished.Payload[0]); Assert.Equal(version.Minor, (byte)connectionEstablished.Payload[1]); long connectionId = (long)connectionEstablished.Payload[2]; From 68a9e74bd6f26ace8f7e31cd8f2487b3da4cb7c2 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Sun, 16 Jul 2023 17:15:07 +0200 Subject: [PATCH 09/16] update Version on events with signature change --- .../System.Net.Http/src/System/Net/Http/HttpTelemetry.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) 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 87ddb23749e99b..ab835eef0ba48e 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 @@ -97,13 +97,13 @@ private void ConnectionEstablished(byte versionMajor, byte versionMinor, long co ConnectionEstablished(versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); } - [Event(4, Level = EventLevel.Informational)] + [Event(4, Level = EventLevel.Informational, Version = 1)] private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? socketAddress) { WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); } - [Event(5, Level = EventLevel.Informational)] + [Event(5, Level = EventLevel.Informational, Version = 1)] private void ConnectionClosed(byte versionMajor, byte versionMinor, long connectionId) { WriteEvent(eventId: 5, versionMajor, versionMinor, connectionId); @@ -115,7 +115,7 @@ private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor, WriteEvent(eventId: 6, timeOnQueueMilliseconds, versionMajor, versionMinor); } - [Event(7, Level = EventLevel.Informational)] + [Event(7, Level = EventLevel.Informational, Version = 1)] public void RequestHeadersStart(long connectionId) { WriteEvent(eventId: 7, connectionId); From 8a3fa5fca34bc5db485a54011d3338994b9b00c7 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Sun, 16 Jul 2023 17:20:56 +0200 Subject: [PATCH 10/16] review feedback --- .../System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs | 4 +++- .../src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs | 2 +- .../System.Net.Http/tests/FunctionalTests/TelemetryTest.cs | 4 ++-- 3 files changed, 6 insertions(+), 4 deletions(-) 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 2d2fd0d05a26d2..35a150b1df61fe 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 @@ -1570,7 +1570,9 @@ public ValueTask SendAsync(HttpRequestMessage request, bool 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); 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 4ed5d066c5a890..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 @@ -55,7 +55,7 @@ internal override async ValueTask SendAsync(HttpRequestMess if (HttpTelemetry.Log.IsEnabled()) { - HttpTelemetry.Log.Redirect(redirectUri.ToString()); + HttpTelemetry.Log.Redirect(redirectUri.AbsoluteUri); } if (NetEventSource.Log.IsEnabled()) { diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 164b976ae2e414..4a43c178c6a7a5 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -883,11 +883,11 @@ await Http11LoopbackServerFactory.Singleton.CreateClientAndServerAsync(async uri ManualResetEventSlim allConnectionsOpen = new(false); int connectionCounter = 0; - Task[] prallelConnectionTasks = Enumerable.Repeat(server, NumParallelRequests) + Task[] parallelConnectionTasks = Enumerable.Repeat(server, NumParallelRequests) .Select(_ => server.AcceptConnectionAsync(HandleConnectionAsync)) .ToArray(); - await Task.WhenAll(prallelConnectionTasks); + await Task.WhenAll(parallelConnectionTasks); async Task HandleConnectionAsync(GenericLoopbackConnection connection) { From e2d86bed4d3d3510765ffbd5d65fc0dd336a00be Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 17 Jul 2023 04:05:51 +0200 Subject: [PATCH 11/16] do not report socket.address tag --- .../SocketsHttpHandler/HttpConnectionBase.cs | 3 +-- .../Metrics/ConnectionMetrics.cs | 9 +------- .../tests/FunctionalTests/MetricsTest.cs | 21 ++++++------------- 3 files changed, 8 insertions(+), 25 deletions(-) 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 46f738b693b8e9..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 @@ -59,8 +59,7 @@ public HttpConnectionBase(HttpConnectionPool pool, IPEndPoint? remoteEndPoint) protocol, pool.IsSecure ? "https" : "http", pool.OriginAuthority.HostValue, - port == defaultPort ? null : port, - remoteEndPoint?.Address?.ToString()); + port == defaultPort ? null : port); _connectionMetrics.ConnectionEstablished(); diff --git a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs index f5edf24d27712b..d047f70766fd05 100644 --- a/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs +++ b/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/ConnectionMetrics.cs @@ -14,10 +14,9 @@ internal sealed class ConnectionMetrics private readonly object _schemeTag; private readonly object _hostTag; private readonly object? _portTag; - private readonly string? _socketAddress; private bool _currentlyIdle; - public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, string scheme, string host, int? port, string? socketAddress) + public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, string scheme, string host, int? port) { _metrics = metrics; _currentConnectionsEnabled = _metrics.CurrentConnections.Enabled; @@ -26,7 +25,6 @@ public ConnectionMetrics(SocketsHttpHandlerMetrics metrics, string protocol, str _schemeTag = scheme; _hostTag = host; _portTag = port; - _socketAddress = socketAddress; } // TagList is a huge struct, so we avoid storing it in a field to reduce the amount we allocate on the heap. @@ -43,11 +41,6 @@ private TagList GetTags() tags.Add("port", _portTag); } - if (_socketAddress is not null) - { - tags.Add("socket.address", _socketAddress); - } - return tags; } diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs index b3d15f6709c292..adbb9dd8b8e4aa 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs @@ -46,20 +46,11 @@ protected static void VerifyOptionalTag(KeyValuePair[] tags, } } - private static void VerifySchemeHostPortSocketAddressTags(KeyValuePair[] tags, Uri uri, bool verifySocketAddress = false) + private static void VerifySchemeHostPort(KeyValuePair[] tags, Uri uri) { VerifyOptionalTag(tags, "scheme", uri.Scheme); VerifyOptionalTag(tags, "host", uri.Host); VerifyOptionalTag(tags, "port", uri.Port); - - if (verifySocketAddress) - { - string socketAddress = (string)tags.Single(t => t.Key == "socket.address").Value; - IPAddress ip = IPAddress.Parse(socketAddress); - Assert.True(ip.Equals(IPAddress.Loopback.MapToIPv6()) || - ip.Equals(IPAddress.Loopback) || - ip.Equals(IPAddress.IPv6Loopback)); - } } protected static void VerifyRequestDuration(Measurement measurement, Uri uri, string? protocol, int? statusCode, string method = "GET") => @@ -69,7 +60,7 @@ protected static void VerifyRequestDuration(string instrumentName, double measur { Assert.Equal(InstrumentNames.RequestDuration, instrumentName); Assert.InRange(measurement, double.Epsilon, 60); - VerifySchemeHostPortSocketAddressTags(tags, uri); + VerifySchemeHostPort(tags, uri); VerifyOptionalTag(tags, "method", method); VerifyOptionalTag(tags, "protocol", protocol); VerifyOptionalTag(tags, "status-code", statusCode); @@ -82,7 +73,7 @@ protected static void VerifyCurrentRequest(string instrumentName, long measureme { Assert.Equal(InstrumentNames.CurrentRequests, instrumentName); Assert.Equal(expectedValue, measurement); - VerifySchemeHostPortSocketAddressTags(tags, uri); + VerifySchemeHostPort(tags, uri); } protected static void VerifyFailedRequests(Measurement measurement, long expectedValue, Uri uri, string? protocol, int? statusCode, string method = "GET") @@ -91,7 +82,7 @@ protected static void VerifyFailedRequests(Measurement measurement, long e KeyValuePair[] tags = measurement.Tags.ToArray(); - VerifySchemeHostPortSocketAddressTags(tags, uri); + VerifySchemeHostPort(tags, uri); Assert.Equal(method, tags.Single(t => t.Key == "method").Value); VerifyOptionalTag(tags, "protocol", protocol); @@ -102,7 +93,7 @@ protected static void VerifyConnectionCounter(string expectedName, string actual { Assert.Equal(expectedName, actualName); Assert.Equal(expectedValue, Assert.IsType(measurement)); - VerifySchemeHostPortSocketAddressTags(tags, uri, verifySocketAddress: true); + VerifySchemeHostPort(tags, uri); VerifyOptionalTag(tags, "protocol", protocol); } @@ -110,7 +101,7 @@ protected static void VerifyConnectionDuration(string instrumentName, double mea { Assert.InRange(measurement, double.Epsilon, 60); Assert.Equal(InstrumentNames.ConnectionDuration, instrumentName); - VerifySchemeHostPortSocketAddressTags(tags, uri, verifySocketAddress: true); + VerifySchemeHostPort(tags, uri); VerifyOptionalTag(tags, "protocol", protocol); } From 36e30df05ed42900e6f9e53f4f866cdc30aebc74 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 17 Jul 2023 04:14:28 +0200 Subject: [PATCH 12/16] revert method name change in tests --- .../tests/FunctionalTests/MetricsTest.cs | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs index adbb9dd8b8e4aa..c27ce9c3ff4818 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs @@ -46,7 +46,7 @@ protected static void VerifyOptionalTag(KeyValuePair[] tags, } } - private static void VerifySchemeHostPort(KeyValuePair[] tags, Uri uri) + private static void VerifySchemeHostPortTags(KeyValuePair[] tags, Uri uri) { VerifyOptionalTag(tags, "scheme", uri.Scheme); VerifyOptionalTag(tags, "host", uri.Host); @@ -60,7 +60,7 @@ protected static void VerifyRequestDuration(string instrumentName, double measur { Assert.Equal(InstrumentNames.RequestDuration, instrumentName); Assert.InRange(measurement, double.Epsilon, 60); - VerifySchemeHostPort(tags, uri); + VerifySchemeHostPortTags(tags, uri); VerifyOptionalTag(tags, "method", method); VerifyOptionalTag(tags, "protocol", protocol); VerifyOptionalTag(tags, "status-code", statusCode); @@ -73,7 +73,7 @@ protected static void VerifyCurrentRequest(string instrumentName, long measureme { Assert.Equal(InstrumentNames.CurrentRequests, instrumentName); Assert.Equal(expectedValue, measurement); - VerifySchemeHostPort(tags, uri); + VerifySchemeHostPortTags(tags, uri); } protected static void VerifyFailedRequests(Measurement measurement, long expectedValue, Uri uri, string? protocol, int? statusCode, string method = "GET") @@ -82,7 +82,7 @@ protected static void VerifyFailedRequests(Measurement measurement, long e KeyValuePair[] tags = measurement.Tags.ToArray(); - VerifySchemeHostPort(tags, uri); + VerifySchemeHostPortTags(tags, uri); Assert.Equal(method, tags.Single(t => t.Key == "method").Value); VerifyOptionalTag(tags, "protocol", protocol); @@ -93,7 +93,7 @@ protected static void VerifyConnectionCounter(string expectedName, string actual { Assert.Equal(expectedName, actualName); Assert.Equal(expectedValue, Assert.IsType(measurement)); - VerifySchemeHostPort(tags, uri); + VerifySchemeHostPortTags(tags, uri); VerifyOptionalTag(tags, "protocol", protocol); } @@ -101,7 +101,7 @@ protected static void VerifyConnectionDuration(string instrumentName, double mea { Assert.InRange(measurement, double.Epsilon, 60); Assert.Equal(InstrumentNames.ConnectionDuration, instrumentName); - VerifySchemeHostPort(tags, uri); + VerifySchemeHostPortTags(tags, uri); VerifyOptionalTag(tags, "protocol", protocol); } From 066391d97e51ca91a8ee9ada5f2ab98af98b2fdd Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 17 Jul 2023 17:36:14 +0200 Subject: [PATCH 13/16] detect non-ssl proxy tunnel --- .../Http/SocketsHttpHandler/HttpConnection.cs | 2 +- .../SocketsHttpHandler/HttpConnectionPool.cs | 6 +++ .../SocketsHttpHandler/HttpContentStream.cs | 2 +- .../tests/FunctionalTests/TelemetryTest.cs | 46 +++++++++++++++++++ 4 files changed, 54 insertions(+), 2 deletions(-) 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 de185001a8c898..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; 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 35a150b1df61fe..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 @@ -1565,6 +1565,12 @@ 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: 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/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 4a43c178c6a7a5..b4feed96ab08cb 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -824,6 +824,52 @@ await GetFactoryForVersion(version).CreateServerAsync((originalServer, originalU }, UseVersion.ToString()).Dispose(); } + [OuterLoop] + [ConditionalTheory(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + [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; From 91c54edb9a98ab7d928ddebb73a8d6c3df5ed883 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 17 Jul 2023 17:41:38 +0200 Subject: [PATCH 14/16] socketAddress -> remoteAddress --- .../System.Net.Http/src/System/Net/Http/HttpTelemetry.cs | 8 ++++---- .../tests/FunctionalTests/TelemetryTest.cs | 2 +- 2 files changed, 5 insertions(+), 5 deletions(-) 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 ab835eef0ba48e..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 @@ -93,14 +93,14 @@ private void RequestFailed(string exceptionMessage) [NonEvent] private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint) { - string? socketAddress = remoteEndPoint?.Address?.ToString(); - ConnectionEstablished(versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); + 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? socketAddress) + private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress) { - WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, socketAddress); + WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); } [Event(5, Level = EventLevel.Informational, Version = 1)] diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index b4feed96ab08cb..174ab7d138fd00 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -464,7 +464,7 @@ protected static void ValidateConnectionEstablishedClosed(ConcurrentQueue<(Event foreach (EventWrittenEventArgs connectionEstablished in connectionsEstablished) { Assert.Equal(7, connectionEstablished.Payload.Count); - Assert.Equal(new[] { "versionMajor", "versionMinor", "connectionId", "scheme", "host", "port", "socketAddress" }, connectionEstablished.PayloadNames); + 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]; From 0fa803edd7636eefd611190a79df309a35aa4692 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Mon, 17 Jul 2023 20:50:02 +0200 Subject: [PATCH 15/16] address CI failures --- .../tests/FunctionalTests/TelemetryTest.cs | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 174ab7d138fd00..57657a2795f944 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -824,8 +824,10 @@ await GetFactoryForVersion(version).CreateServerAsync((originalServer, originalU }, UseVersion.ToString()).Dispose(); } + public static bool SupportsRemoteExecutorAndAlpn = RemoteExecutor.IsSupported && PlatformDetection.SupportsAlpn; + [OuterLoop] - [ConditionalTheory(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] + [ConditionalTheory(nameof(SupportsRemoteExecutorAndAlpn))] [InlineData(false)] [InlineData(true)] public void EventSource_Proxy_LogsIPAddress(bool useSsl) @@ -900,12 +902,13 @@ public sealed class TelemetryTest_Http11 : TelemetryTest public TelemetryTest_Http11(ITestOutputHelper output) : base(output) { } [OuterLoop] + [ActiveIssue("https://github.com/dotnet/runtime/issues/89035", TestPlatforms.Browser)] [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] public void EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest() { RemoteExecutor.Invoke(async () => { - TimeSpan timeout = TimeSpan.FromSeconds(30); + TimeSpan timeout = TimeSpan.FromSeconds(60); const int NumParallelRequests = 4; using var listener = new TestEventListener("System.Net.Http", EventLevel.Verbose, eventCounterInterval: 0.1d); @@ -947,7 +950,7 @@ async Task HandleConnectionAsync(GenericLoopbackConnection connection) } }); await WaitForEventCountersAsync(events); - }).WaitAsync(timeout); + }); Assert.DoesNotContain(events, e => e.Event.EventId == 0); // errors from the EventSource itself From 86006f4b074c7421b64a3400561d1d924e703ab9 Mon Sep 17 00:00:00 2001 From: antonfirsov Date: Tue, 18 Jul 2023 00:14:54 +0200 Subject: [PATCH 16/16] oops --- .../System.Net.Http/tests/FunctionalTests/TelemetryTest.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs index 57657a2795f944..82fac90c58f020 100644 --- a/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs +++ b/src/libraries/System.Net.Http/tests/FunctionalTests/TelemetryTest.cs @@ -902,7 +902,7 @@ public sealed class TelemetryTest_Http11 : TelemetryTest public TelemetryTest_Http11(ITestOutputHelper output) : base(output) { } [OuterLoop] - [ActiveIssue("https://github.com/dotnet/runtime/issues/89035", TestPlatforms.Browser)] + [ActiveIssue("https://github.com/dotnet/runtime/issues/89035", TestPlatforms.OSX)] [ConditionalFact(typeof(RemoteExecutor), nameof(RemoteExecutor.IsSupported))] public void EventSource_ParallelRequests_LogsNewConnectionIdForEachRequest() {