Skip to content

Commit

Permalink
System.Net Telemetry style changes (dotnet#41527)
Browse files Browse the repository at this point in the history 
* Change HandshakeStop SslProtocols parameter to enum

* Parameterize Http11/Http20 events

* Add dummy request to ensure Http2 settings are received
  • Loading branch information
@MihaZupan
MihaZupan committed Aug 31, 2020
1 parent af1a3dc commit 41ffe5d
Show file tree
Hide file tree
Showing 5 changed files with 231 additions and 83 deletions.
106 changes: 87 additions & 19 deletions src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,8 @@ internal sealed class HttpTelemetry : EventSource
private PollingCounter? _abortedRequestsCounter;
private PollingCounter? _totalHttp11ConnectionsCounter;
private PollingCounter? _totalHttp20ConnectionsCounter;
private EventCounter? _requestsQueueDurationCounter;
private EventCounter? _http11RequestsQueueDurationCounter;
private EventCounter? _http20RequestsQueueDurationCounter;

private long _startedRequests;
private long _stoppedRequests;
Expand Down Expand Up @@ -57,46 +58,71 @@ public void RequestAborted()
}

[Event(4, Level = EventLevel.Informational)]
private void ConnectionEstablished(byte versionMajor, byte versionMinor)
{
WriteEvent(eventId: 4, versionMajor, versionMinor);
}

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

[Event(6, Level = EventLevel.Informational)]
private void RequestLeftQueue(double timeOnQueueMilliseconds, byte versionMajor, byte versionMinor)
{
WriteEvent(eventId: 6, timeOnQueueMilliseconds, versionMajor, versionMinor);
}

[Event(7, Level = EventLevel.Informational)]
public void ResponseHeadersBegin()
{
WriteEvent(eventId: 7);
}

[NonEvent]
public void Http11ConnectionEstablished()
{
Interlocked.Increment(ref _openedHttp11Connections);
WriteEvent(eventId: 4);
ConnectionEstablished(versionMajor: 1, versionMinor: 1);
}

[Event(5, Level = EventLevel.Informational)]
[NonEvent]
public void Http11ConnectionClosed()
{
long count = Interlocked.Decrement(ref _openedHttp11Connections);
Debug.Assert(count >= 0);
WriteEvent(eventId: 5);
ConnectionClosed(versionMajor: 1, versionMinor: 1);
}

[Event(6, Level = EventLevel.Informational)]
[NonEvent]
public void Http20ConnectionEstablished()
{
Interlocked.Increment(ref _openedHttp20Connections);
WriteEvent(eventId: 6);
ConnectionEstablished(versionMajor: 2, versionMinor: 0);
}

[Event(7, Level = EventLevel.Informational)]
[NonEvent]
public void Http20ConnectionClosed()
{
long count = Interlocked.Decrement(ref _openedHttp20Connections);
Debug.Assert(count >= 0);
WriteEvent(eventId: 7);
ConnectionClosed(versionMajor: 2, versionMinor: 0);
}

[Event(8, Level = EventLevel.Informational)]
[NonEvent]
public void Http11RequestLeftQueue(double timeOnQueueMilliseconds)
{
_requestsQueueDurationCounter!.WriteMetric(timeOnQueueMilliseconds);
WriteEvent(eventId: 8, timeOnQueueMilliseconds);
_http11RequestsQueueDurationCounter!.WriteMetric(timeOnQueueMilliseconds);
RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 1, versionMinor: 1);
}

[Event(9, Level = EventLevel.Informational)]
public void ResponseHeadersBegin()
[NonEvent]
public void Http20RequestLeftQueue(double timeOnQueueMilliseconds)
{
WriteEvent(eventId: 9);
_http20RequestsQueueDurationCounter!.WriteMetric(timeOnQueueMilliseconds);
RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 2, versionMinor: 0);
}

protected override void OnEventCommand(EventCommandEventArgs command)
Expand Down Expand Up @@ -152,11 +178,17 @@ protected override void OnEventCommand(EventCommandEventArgs command)
DisplayName = "Current Http 2.0 Connections"
};

_requestsQueueDurationCounter ??= new EventCounter("http11-requests-queue-duration", this)
_http11RequestsQueueDurationCounter ??= new EventCounter("http11-requests-queue-duration", this)
{
DisplayName = "HTTP 1.1 Requests Queue Duration",
DisplayUnits = "ms"
};

_http20RequestsQueueDurationCounter ??= new EventCounter("http20-requests-queue-duration", this)
{
DisplayName = "HTTP 2.0 Requests Queue Duration",
DisplayUnits = "ms"
};
}
}

Expand All @@ -174,7 +206,7 @@ private unsafe void WriteEvent(int eventId, string? arg1, string? arg2, int arg3
fixed (char* arg4Ptr = arg4)
{
const int NumEventDatas = 6;
var descrs = stackalloc EventData[NumEventDatas];
EventData* descrs = stackalloc EventData[NumEventDatas];

descrs[0] = new EventData
{
Expand Down Expand Up @@ -213,17 +245,53 @@ private unsafe void WriteEvent(int eventId, string? arg1, string? arg2, int arg3
}

[NonEvent]
private unsafe void WriteEvent(int eventId, double arg1)
private unsafe void WriteEvent(int eventId, double arg1, byte arg2, byte arg3)
{
if (IsEnabled())
{
EventData descr = new EventData
const int NumEventDatas = 3;
EventData* descrs = stackalloc EventData[NumEventDatas];

descrs[0] = new EventData
{
DataPointer = (IntPtr)(&arg1),
Size = sizeof(double)
};
descrs[1] = new EventData
{
DataPointer = (IntPtr)(&arg2),
Size = sizeof(byte)
};
descrs[2] = new EventData
{
DataPointer = (IntPtr)(&arg3),
Size = sizeof(byte)
};

WriteEventCore(eventId, NumEventDatas, descrs);
}
}

[NonEvent]
private unsafe void WriteEvent(int eventId, byte arg1, byte arg2)
{
if (IsEnabled())
{
const int NumEventDatas = 2;
EventData* descrs = stackalloc EventData[NumEventDatas];

descrs[0] = new EventData
{
DataPointer = (IntPtr)(&arg1),
Size = sizeof(byte)
};
descrs[1] = new EventData
{
DataPointer = (IntPtr)(&arg2),
Size = sizeof(byte)
};

WriteEventCore(eventId, eventDataCount: 1, &descr);
WriteEventCore(eventId, NumEventDatas, descrs);
}
}
}
Expand Down
21 changes: 15 additions & 6 deletions src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
using System.Threading;
using System.Threading.Channels;
using System.Threading.Tasks;
using Microsoft.Extensions.Internal;

namespace System.Net.Http
{
Expand Down Expand Up @@ -1308,16 +1309,24 @@ private async ValueTask<Http2Stream> SendHeadersAsync(HttpRequestMessage request
// in order to avoid consuming resources in potentially many requests waiting for access.
try
{
if (_pool.EnableMultipleHttp2Connections)
if (!_concurrentStreams.TryRequestCreditNoWait(1))
{
if (!_concurrentStreams.TryRequestCreditNoWait(1))
if (_pool.EnableMultipleHttp2Connections)
{
throw new HttpRequestException(null, null, RequestRetryType.RetryOnNextConnection);
}
}
else
{
await _concurrentStreams.RequestCreditAsync(1, cancellationToken).ConfigureAwait(false);

if (HttpTelemetry.Log.IsEnabled())
{
// Only log Http20RequestLeftQueue if we spent time waiting on the queue
ValueStopwatch stopwatch = ValueStopwatch.StartNew();
await _concurrentStreams.RequestCreditAsync(1, cancellationToken).ConfigureAwait(false);
HttpTelemetry.Log.Http20RequestLeftQueue(stopwatch.GetElapsedTime().TotalMilliseconds);
}
else
{
await _concurrentStreams.RequestCreditAsync(1, cancellationToken).ConfigureAwait(false);
}
}
}
catch (ObjectDisposedException)
Expand Down
Loading

0 comments on commit 41ffe5d

Please sign in to comment.