Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Adjust System.Net.Http metrics #89809

Merged
merged 10 commits into from
Aug 3, 2023
Original file line number Diff line number Diff line change
Expand Up @@ -176,7 +176,7 @@ internal static HttpMethod Normalize(HttpMethod method)
method;
}

private static HttpMethod? GetKnownMethod(ReadOnlySpan<char> method)
internal static HttpMethod? GetKnownMethod(ReadOnlySpan<char> method)
{
if (method.Length >= 3) // 3 == smallest known method
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -108,15 +108,12 @@ public static void AddCallback(HttpRequestMessage request, Action<HttpMetricsEnr
return context;
}

internal void RecordWithEnrichment(HttpRequestMessage request,
internal void RecordDurationWithEnrichment(HttpRequestMessage request,
HttpResponseMessage? response,
Exception? exception,
long startTimestamp,
TimeSpan durationTime,
in TagList commonTags,
bool recordRequestDuration,
bool recordFailedRequests,
Histogram<double> requestDuration,
Counter<long> failedRequests)
Histogram<double> requestDuration)
{
_request = request;
_response = response;
Expand All @@ -140,16 +137,7 @@ internal void RecordWithEnrichment(HttpRequestMessage request,
callback(this);
}

if (recordRequestDuration)
{
TimeSpan duration = Stopwatch.GetElapsedTime(startTimestamp, Stopwatch.GetTimestamp());
requestDuration.Record(duration.TotalSeconds, CollectionsMarshal.AsSpan(_tags));
}

if (recordFailedRequests)
{
failedRequests.Add(1, CollectionsMarshal.AsSpan(_tags));
}
requestDuration.Record(durationTime.TotalSeconds, CollectionsMarshal.AsSpan(_tags));
}
finally
{
Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Metrics;
using System.Threading;
Expand All @@ -11,8 +12,7 @@ namespace System.Net.Http.Metrics
internal sealed class MetricsHandler : HttpMessageHandlerStage
{
private readonly HttpMessageHandler _innerHandler;
private readonly UpDownCounter<long> _currentRequests;
private readonly Counter<long> _failedRequests;
private readonly UpDownCounter<long> _activeRequests;
private readonly Histogram<double> _requestsDuration;

public MetricsHandler(HttpMessageHandler innerHandler, IMeterFactory? meterFactory, out Meter meter)
Expand All @@ -22,21 +22,18 @@ public MetricsHandler(HttpMessageHandler innerHandler, IMeterFactory? meterFacto
meter = meterFactory?.Create("System.Net.Http") ?? SharedMeter.Instance;

// Meter has a cache for the instruments it owns
_currentRequests = meter.CreateUpDownCounter<long>(
"http-client-current-requests",
_activeRequests = meter.CreateUpDownCounter<long>(
"http.client.active_requests",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

unit should be "{request}"

description: "Number of outbound HTTP requests that are currently active on the client.");
_failedRequests = meter.CreateCounter<long>(
"http-client-failed-requests",
description: "Number of outbound HTTP requests that have failed.");
_requestsDuration = meter.CreateHistogram<double>(
"http-client-request-duration",
"http.client.request.duration",
unit: "s",
description: "The duration of outbound HTTP requests.");
MihaZupan marked this conversation as resolved.
Show resolved Hide resolved
}

internal override ValueTask<HttpResponseMessage> SendAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken)
{
if (_currentRequests.Enabled || _failedRequests.Enabled || _requestsDuration.Enabled)
if (_activeRequests.Enabled || _requestsDuration.Enabled)
{
return SendAsyncWithMetrics(request, async, cancellationToken);
}
Expand Down Expand Up @@ -83,67 +80,90 @@ protected override void Dispose(bool disposing)

private (long StartTimestamp, bool RecordCurrentRequests) RequestStart(HttpRequestMessage request)
{
bool recordCurrentRequests = _currentRequests.Enabled;
bool recordCurrentRequests = _activeRequests.Enabled;
long startTimestamp = Stopwatch.GetTimestamp();

if (recordCurrentRequests)
{
TagList tags = InitializeCommonTags(request);
_currentRequests.Add(1, tags);
_activeRequests.Add(1, tags);
}

return (startTimestamp, recordCurrentRequests);
}

private void RequestStop(HttpRequestMessage request, HttpResponseMessage? response, Exception? exception, long startTimestamp, bool recordCurrentRequsts)
private void RequestStop(HttpRequestMessage request, HttpResponseMessage? response, Exception? exception, long startTimestamp, bool recordCurrentRequests)
{
TagList tags = InitializeCommonTags(request);

if (recordCurrentRequsts)
if (recordCurrentRequests)
{
_currentRequests.Add(-1, tags);
_activeRequests.Add(-1, tags);
}

bool recordRequestDuration = _requestsDuration.Enabled;
bool recordFailedRequests = _failedRequests.Enabled && response is null;
if (!_requestsDuration.Enabled)
{
return;
}

HttpMetricsEnrichmentContext? enrichmentContext = null;
if (recordRequestDuration || recordFailedRequests)
if (response is not null)
{
if (response is not null)
{
tags.Add("status-code", GetBoxedStatusCode((int)response.StatusCode));
tags.Add("protocol", GetProtocolName(response.Version));
}
enrichmentContext = HttpMetricsEnrichmentContext.GetEnrichmentContextForRequest(request);
tags.Add("http.response.status_code", GetBoxedStatusCode((int)response.StatusCode));
tags.Add("network.protocol.version", GetProtocolVersionString(response.Version));
}
else
{
Debug.Assert(exception is not null);
tags.Add("http.error.reason", GetErrorReason(exception));
}
TimeSpan durationTime = Stopwatch.GetElapsedTime(startTimestamp, Stopwatch.GetTimestamp());

HttpMetricsEnrichmentContext? enrichmentContext = HttpMetricsEnrichmentContext.GetEnrichmentContextForRequest(request);
if (enrichmentContext is null)
{
if (recordRequestDuration)
{
TimeSpan duration = Stopwatch.GetElapsedTime(startTimestamp, Stopwatch.GetTimestamp());
_requestsDuration.Record(duration.TotalSeconds, tags);
}

if (recordFailedRequests)
{
_failedRequests.Add(1, tags);
}
_requestsDuration.Record(durationTime.TotalSeconds, tags);
}
else
{
enrichmentContext.RecordWithEnrichment(request, response, exception, startTimestamp, tags, recordRequestDuration, recordFailedRequests, _requestsDuration, _failedRequests);
enrichmentContext.RecordDurationWithEnrichment(request, response, exception, durationTime, tags, _requestsDuration);
}
}

private static string GetErrorReason(Exception exception)
{
if (exception is OperationCanceledException)
{
return "cancellation";
}
else if (exception is HttpRequestException e)
{
Debug.Assert(Enum.GetValues<HttpRequestError>().Length == 12, "We need to extend the mapping in case new values are added to HttpRequestError.");
return e.HttpRequestError switch
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
{
HttpRequestError.NameResolutionError => "name_resolution_error",
HttpRequestError.ConnectionError => "connection_error",
HttpRequestError.SecureConnectionError => "secure_connection_error",
HttpRequestError.HttpProtocolError => "http_protocol_error",
HttpRequestError.ExtendedConnectNotSupported => "extended_connect_not_supported",
HttpRequestError.VersionNegotiationError => "version_negotiation_error",
HttpRequestError.UserAuthenticationError => "user_authentication_error",
HttpRequestError.ProxyTunnelError => "proxy_tunnel_error",
HttpRequestError.InvalidResponse => "invalid_response",
HttpRequestError.ResponseEnded => "response_ended",
HttpRequestError.ConfigurationLimitExceeded => "configuration_limit_exceeded",
_ => "_OTHER"
};
}
return "_OTHER";
}

private static string GetProtocolName(Version httpVersion) => (httpVersion.Major, httpVersion.Minor) switch
private static string GetProtocolVersionString(Version httpVersion) => (httpVersion.Major, httpVersion.Minor) switch
{
(1, 0) => "HTTP/1.0",
(1, 1) => "HTTP/1.1",
(2, 0) => "HTTP/2",
(3, 0) => "HTTP/3",
_ => $"HTTP/{httpVersion.Major}.{httpVersion.Minor}"
(1, 0) => "1.0",
(1, 1) => "1.1",
(2, 0) => "2.0",
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think @JamesNK uses "2" and "3" for HTTP/2 and HTTP/3 for asp.net core and kestrel, which, I believe, matches their RFCs (HTTP/2, HTTP/3).

can we still unify?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yup I will open a follow-up PR.

(3, 0) => "3.0",
_ => httpVersion.ToString()
};

private static TagList InitializeCommonTags(HttpRequestMessage request)
Expand All @@ -152,19 +172,26 @@ private static TagList InitializeCommonTags(HttpRequestMessage request)

if (request.RequestUri is Uri requestUri && requestUri.IsAbsoluteUri)
{
tags.Add("scheme", requestUri.Scheme);
tags.Add("host", requestUri.Host);
tags.Add("url.scheme", requestUri.Scheme);
tags.Add("server.address", requestUri.Host);
// Add port tag when not the default value for the current scheme
if (!requestUri.IsDefaultPort)
{
tags.Add("port", requestUri.Port);
tags.Add("server.port", requestUri.Port);
}
}
tags.Add("method", request.Method.Method);
tags.Add(GetMethodTag(request.Method));

return tags;
}

internal static KeyValuePair<string, object?> GetMethodTag(HttpMethod method)
{
// Return canonical names for known methods and "_OTHER" for unknown ones.
HttpMethod? known = HttpMethod.GetKnownMethod(method.Method);
return new KeyValuePair<string, object?>("http.request.method", known?.Method ?? "_OTHER");
}

private static object[]? s_boxedStatusCodes;

private static object GetBoxedStatusCode(int statusCode)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -197,7 +197,7 @@ public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, lon
{
TimeSpan duration = Stopwatch.GetElapsedTime(queueStartingTimestamp);

_pool.Settings._metrics!.RequestLeftQueue(Pool, duration, versionMajor: 3);
_pool.Settings._metrics!.RequestLeftQueue(request, Pool, duration, versionMajor: 3);

if (HttpTelemetry.Log.IsEnabled())
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -42,28 +42,27 @@ public HttpConnectionBase(HttpConnectionPool pool, IPEndPoint? remoteEndPoint)

SocketsHttpHandlerMetrics metrics = pool.Settings._metrics;

if (metrics.CurrentConnections.Enabled ||
metrics.IdleConnections.Enabled ||
metrics.ConnectionDuration.Enabled)
if (metrics.OpenConnections.Enabled || metrics.ConnectionDuration.Enabled)
{
// While requests may report HTTP/1.0 as the protocol, we treat all HTTP/1.X connections as HTTP/1.1.
string protocol =
this is HttpConnection ? "HTTP/1.1" :
this is Http2Connection ? "HTTP/2" :
"HTTP/3";
this is HttpConnection ? "1.1" :
this is Http2Connection ? "2.0" :
"3.0";

_connectionMetrics = new ConnectionMetrics(
metrics,
protocol,
pool.IsSecure ? "https" : "http",
pool.OriginAuthority.HostValue,
pool.IsDefaultPort ? null : pool.OriginAuthority.Port);
pool.IsDefaultPort ? null : pool.OriginAuthority.Port,
remoteEndPoint?.Address?.ToString());

_connectionMetrics.ConnectionEstablished();

MarkConnectionAsIdle();
}

_idleSinceTickCount = _creationTickCount;

if (HttpTelemetry.Log.IsEnabled())
{
_httpTelemetryMarkedConnectionAsOpened = true;
Expand Down Expand Up @@ -97,13 +96,12 @@ public void MarkConnectionAsClosed()
public void MarkConnectionAsIdle()
{
_idleSinceTickCount = Environment.TickCount64;

_connectionMetrics?.MarkAsIdle();
_connectionMetrics?.IdleStateChanged(idle: true);
}

public void MarkConnectionAsNotIdle()
{
_connectionMetrics?.MarkAsNotIdle();
_connectionMetrics?.IdleStateChanged(idle: false);
}

/// <summary>Uses <see cref="HeaderDescriptor.GetHeaderValue"/>, but first special-cases several known headers for which we can use caching.</summary>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1084,7 +1084,7 @@ public async ValueTask<HttpResponseMessage> SendWithVersionDetectionAndRetryAsyn
if (!TryGetPooledHttp2Connection(request, out Http2Connection? connection, out http2ConnectionWaiter) &&
http2ConnectionWaiter != null)
{
connection = await http2ConnectionWaiter.WaitForConnectionAsync(this, async, cancellationToken).ConfigureAwait(false);
connection = await http2ConnectionWaiter.WaitForConnectionAsync(request, this, async, cancellationToken).ConfigureAwait(false);
}

Debug.Assert(connection is not null || !_http2Enabled);
Expand Down Expand Up @@ -1116,7 +1116,7 @@ public async ValueTask<HttpResponseMessage> SendWithVersionDetectionAndRetryAsyn
// Use HTTP/1.x.
if (!TryGetPooledHttp11Connection(request, async, out HttpConnection? connection, out http11ConnectionWaiter))
{
connection = await http11ConnectionWaiter.WaitForConnectionAsync(this, async, cancellationToken).ConfigureAwait(false);
connection = await http11ConnectionWaiter.WaitForConnectionAsync(request, this, async, cancellationToken).ConfigureAwait(false);
}

connection.Acquire(); // In case we are doing Windows (i.e. connection-based) auth, we need to ensure that we hold on to this specific connection while auth is underway.
Expand Down Expand Up @@ -2620,14 +2620,14 @@ private sealed class HttpConnectionWaiter<T> : TaskCompletionSourceWithCancellat
// Distinguish connection cancellation that happens because the initiating request is cancelled or completed on a different connection.
public bool CancelledByOriginatingRequestCompletion { get; set; }

public ValueTask<T> WaitForConnectionAsync(HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
public ValueTask<T> WaitForConnectionAsync(HttpRequestMessage request, HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
{
return HttpTelemetry.Log.IsEnabled() || pool.Settings._metrics!.RequestsQueueDuration.Enabled
? WaitForConnectionWithTelemetryAsync(pool, async, requestCancellationToken)
? WaitForConnectionWithTelemetryAsync(request, pool, async, requestCancellationToken)
: WaitWithCancellationAsync(async, requestCancellationToken);
}

private async ValueTask<T> WaitForConnectionWithTelemetryAsync(HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
private async ValueTask<T> WaitForConnectionWithTelemetryAsync(HttpRequestMessage request, HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
{
Debug.Assert(typeof(T) == typeof(HttpConnection) || typeof(T) == typeof(Http2Connection));

Expand All @@ -2641,7 +2641,7 @@ private async ValueTask<T> WaitForConnectionWithTelemetryAsync(HttpConnectionPoo
TimeSpan duration = Stopwatch.GetElapsedTime(startingTimestamp);
int versionMajor = typeof(T) == typeof(HttpConnection) ? 1 : 2;

pool.Settings._metrics!.RequestLeftQueue(pool, duration, versionMajor);
pool.Settings._metrics!.RequestLeftQueue(request, pool, duration, versionMajor);

if (HttpTelemetry.Log.IsEnabled())
{
Expand Down
Loading
Loading