Skip to content

Commit

Permalink
Extend SocketsHttpHandler Connection and Request telemetry (#88853)
Browse files Browse the repository at this point in the history
Fixes #63159, fixes #85729.
  • Loading branch information
antonfirsov authored Jul 18, 2023
1 parent 31ffdb7 commit 1db1ba4
Show file tree
Hide file tree
Showing 10 changed files with 368 additions and 69 deletions.
120 changes: 97 additions & 23 deletions src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs
Original file line number Diff line number Diff line change
Expand Up @@ -90,16 +90,23 @@ private void RequestFailed(string exceptionMessage)
WriteEvent(eventId: 3, exceptionMessage);
}

[Event(4, Level = EventLevel.Informational)]
private void ConnectionEstablished(byte versionMajor, byte versionMinor)
[NonEvent]
private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint)
{
string? remoteAddress = remoteEndPoint?.Address?.ToString();
ConnectionEstablished(versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress);
}

[Event(4, Level = EventLevel.Informational, Version = 1)]
private void ConnectionEstablished(byte versionMajor, byte versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress)
{
WriteEvent(eventId: 4, versionMajor, versionMinor);
WriteEvent(eventId: 4, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress);
}

[Event(5, Level = EventLevel.Informational)]
private void ConnectionClosed(byte versionMajor, byte versionMinor)
[Event(5, Level = EventLevel.Informational, Version = 1)]
private void ConnectionClosed(byte versionMajor, byte versionMinor, long connectionId)
{
WriteEvent(eventId: 5, versionMajor, versionMinor);
WriteEvent(eventId: 5, versionMajor, versionMinor, connectionId);
}

[Event(6, Level = EventLevel.Informational)]
Expand All @@ -108,10 +115,10 @@ private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor,
WriteEvent(eventId: 6, timeOnQueueMilliseconds, versionMajor, versionMinor);
}

[Event(7, Level = EventLevel.Informational)]
public void RequestHeadersStart()
[Event(7, Level = EventLevel.Informational, Version = 1)]
public void RequestHeadersStart(long connectionId)
{
WriteEvent(eventId: 7);
WriteEvent(eventId: 7, connectionId);
}

[Event(8, Level = EventLevel.Informational)]
Expand Down Expand Up @@ -162,49 +169,55 @@ private void RequestFailedDetailed(string exception)
WriteEvent(eventId: 15, exception);
}

[Event(16, Level = EventLevel.Informational)]
public void Redirect(string redirectUri)
{
WriteEvent(eventId: 16, redirectUri);
}

[NonEvent]
public void Http11ConnectionEstablished()
public void Http11ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint)
{
Interlocked.Increment(ref _openedHttp11Connections);
ConnectionEstablished(versionMajor: 1, versionMinor: 1);
ConnectionEstablished(versionMajor: 1, versionMinor: 1, connectionId, scheme, host, port, remoteEndPoint);
}

[NonEvent]
public void Http11ConnectionClosed()
public void Http11ConnectionClosed(long connectionId)
{
long count = Interlocked.Decrement(ref _openedHttp11Connections);
Debug.Assert(count >= 0);
ConnectionClosed(versionMajor: 1, versionMinor: 1);
ConnectionClosed(versionMajor: 1, versionMinor: 1, connectionId);
}

[NonEvent]
public void Http20ConnectionEstablished()
public void Http20ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint)
{
Interlocked.Increment(ref _openedHttp20Connections);
ConnectionEstablished(versionMajor: 2, versionMinor: 0);
ConnectionEstablished(versionMajor: 2, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint);
}

[NonEvent]
public void Http20ConnectionClosed()
public void Http20ConnectionClosed(long connectionId)
{
long count = Interlocked.Decrement(ref _openedHttp20Connections);
Debug.Assert(count >= 0);
ConnectionClosed(versionMajor: 2, versionMinor: 0);
ConnectionClosed(versionMajor: 2, versionMinor: 0, connectionId);
}

[NonEvent]
public void Http30ConnectionEstablished()
public void Http30ConnectionEstablished(long connectionId, string scheme, string host, int port, IPEndPoint? remoteEndPoint)
{
Interlocked.Increment(ref _openedHttp30Connections);
ConnectionEstablished(versionMajor: 3, versionMinor: 0);
ConnectionEstablished(versionMajor: 3, versionMinor: 0, connectionId, scheme, host, port, remoteEndPoint);
}

[NonEvent]
public void Http30ConnectionClosed()
public void Http30ConnectionClosed(long connectionId)
{
long count = Interlocked.Decrement(ref _openedHttp30Connections);
Debug.Assert(count >= 0);
ConnectionClosed(versionMajor: 3, versionMinor: 0);
ConnectionClosed(versionMajor: 3, versionMinor: 0, connectionId);
}

[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode",
Expand Down Expand Up @@ -293,9 +306,9 @@ private unsafe void WriteEvent(int eventId, double arg1, byte arg2, byte arg3)
[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode",
Justification = "Parameters to this method are primitive and are trimmer safe")]
[NonEvent]
private unsafe void WriteEvent(int eventId, byte arg1, byte arg2)
private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3)
{
const int NumEventDatas = 2;
const int NumEventDatas = 3;
EventData* descrs = stackalloc EventData[NumEventDatas];

descrs[0] = new EventData
Expand All @@ -308,6 +321,67 @@ private unsafe void WriteEvent(int eventId, byte arg1, byte arg2)
DataPointer = (IntPtr)(&arg2),
Size = sizeof(byte)
};
descrs[2] = new EventData
{
DataPointer = (IntPtr)(&arg3),
Size = sizeof(long)
};

WriteEventCore(eventId, NumEventDatas, descrs);
}

[UnconditionalSuppressMessage("ReflectionAnalysis", "IL2026:RequiresUnreferencedCode",
Justification = "Parameters to this method are primitive and are trimmer safe")]
[NonEvent]
private unsafe void WriteEvent(int eventId, byte arg1, byte arg2, long arg3, string? arg4, string arg5, int arg6, string? arg7)
{
arg4 ??= "";
arg5 ??= "";
arg7 ??= "";

const int NumEventDatas = 7;
EventData* descrs = stackalloc EventData[NumEventDatas];

fixed (char* arg4Ptr = arg4)
fixed (char* arg5Ptr = arg5)
fixed (char* arg7Ptr = arg7)
{
descrs[0] = new EventData
{
DataPointer = (IntPtr)(&arg1),
Size = sizeof(byte)
};
descrs[1] = new EventData
{
DataPointer = (IntPtr)(&arg2),
Size = sizeof(byte)
};
descrs[2] = new EventData
{
DataPointer = (IntPtr)(&arg3),
Size = sizeof(long)
};
descrs[3] = new EventData
{
DataPointer = (IntPtr)arg4Ptr,
Size = (arg4.Length + 1) * sizeof(char)
};
descrs[4] = new EventData
{
DataPointer = (IntPtr)arg5Ptr,
Size = (arg5.Length + 1) * sizeof(char)
};
descrs[5] = new EventData
{
DataPointer = (IntPtr)(&arg6),
Size = sizeof(int)
};
descrs[6] = new EventData
{
DataPointer = (IntPtr)arg7Ptr,
Size = (arg7.Length + 1) * sizeof(char)
};
}

WriteEventCore(eventId, NumEventDatas, descrs);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -1656,7 +1656,7 @@ private async ValueTask<Http2Stream> 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.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -73,8 +73,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);
Expand Down Expand Up @@ -515,7 +516,7 @@ public async Task<HttpResponseMessage> 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);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@ namespace System.Net.Http
{
internal abstract class HttpConnectionBase : IDisposable, IHttpTrace
{
private static long s_connectionCounter = -1;

// May be null if none of the counters were enabled when the connection was established.
private readonly ConnectionMetrics? _connectionMetrics;

Expand All @@ -31,7 +33,9 @@ internal abstract class HttpConnectionBase : IDisposable, IHttpTrace
/// <summary>Cached string for the last Server header received on this connection.</summary>
private string? _lastServerHeaderValue;

public HttpConnectionBase(HttpConnectionPool pool)
public long Id { get; } = Interlocked.Increment(ref s_connectionCounter);

public HttpConnectionBase(HttpConnectionPool pool, IPEndPoint? remoteEndPoint)
{
Debug.Assert(this is HttpConnection or Http2Connection or Http3Connection);
Debug.Assert(pool.Settings._metrics is not null);
Expand Down Expand Up @@ -64,9 +68,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);
}
}

Expand All @@ -79,9 +87,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);
}
}
}
Expand Down Expand Up @@ -125,7 +133,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}, " +
Expand All @@ -134,7 +142,7 @@ protected void TraceConnection(Stream stream)
}
else
{
Trace($"{this}");
Trace($"{this}. Id:{Id}");
}
}

Expand Down
Loading

0 comments on commit 1db1ba4

Please sign in to comment.