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

Add bucket bound hints to Networking histograms #104629

Merged
merged 9 commits into from
Jul 10, 2024
1 change: 1 addition & 0 deletions src/libraries/System.Net.Http/src/System.Net.Http.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
<Compile Include="System\Net\Http\DelegatingHandler.cs" />
<Compile Include="System\Net\Http\DiagnosticsHandler.cs" />
<Compile Include="System\Net\Http\DiagnosticsHandlerLoggingStrings.cs" />
<Compile Include="System\Net\Http\DiagnosticsHelper.cs" />
<Compile Include="System\Net\Http\EmptyContent.cs" />
<Compile Include="System\Net\Http\EmptyReadStream.cs" />
<Compile Include="System\Net\Http\FormUrlEncodedContent.cs" />
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

using System.Diagnostics.Metrics;

namespace System.Net.Http
{
internal static class DiagnosticsHelper
{
// OTel bucket boundary recommendation for 'http.request.duration':
// https://github.com/open-telemetry/semantic-conventions/blob/release/v1.23.x/docs/http/http-metrics.md#metric-httpclientrequestduration
// We are using these boundaries for all network requests that are expected to be short.
antonfirsov marked this conversation as resolved.
Show resolved Hide resolved
public static InstrumentAdvice<double> ShortHistogramAdvice { get; } = new()
{
HistogramBucketBoundaries = [0.005, 0.01, 0.025, 0.05, 0.075, 0.1, 0.25, 0.5, 0.75, 1, 2.5, 5, 7.5, 10]
};
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,8 @@ public MetricsHandler(HttpMessageHandler innerHandler, IMeterFactory? meterFacto
_requestsDuration = meter.CreateHistogram<double>(
"http.client.request.duration",
unit: "s",
description: "Duration of HTTP client requests.");
description: "Duration of HTTP client requests.",
advice: DiagnosticsHelper.ShortHistogramAdvice);
}

internal override ValueTask<HttpResponseMessage> SendAsync(HttpRequestMessage request, bool async, CancellationToken cancellationToken)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,12 +16,18 @@ internal sealed class SocketsHttpHandlerMetrics(Meter meter)
public readonly Histogram<double> ConnectionDuration = meter.CreateHistogram<double>(
name: "http.client.connection.duration",
unit: "s",
description: "The duration of successfully established outbound HTTP connections.");
description: "The duration of successfully established outbound HTTP connections.",
advice: new InstrumentAdvice<double>()
{
// These values are not based on a standard and may change in the future.
HistogramBucketBoundaries = [0.01, 0.02, 0.05, 0.1, 0.2, 0.5, 1, 2, 5, 10, 30, 60, 120, 300]
});

public readonly Histogram<double> RequestsQueueDuration = meter.CreateHistogram<double>(
name: "http.client.request.time_in_queue",
unit: "s",
description: "The amount of time requests spent on a queue waiting for an available connection.");
description: "The amount of time requests spent on a queue waiting for an available connection.",
advice: DiagnosticsHelper.ShortHistogramAdvice);

public void RequestLeftQueue(HttpRequestMessage request, HttpConnectionPool pool, TimeSpan duration, int versionMajor)
{
Expand Down
44 changes: 44 additions & 0 deletions src/libraries/System.Net.Http/tests/FunctionalTests/MetricsTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -161,6 +161,8 @@ protected sealed class InstrumentRecorder<T> : IDisposable where T : struct
private Meter? _meter;

public Action? MeasurementRecorded;
public Action<IReadOnlyList<T>> VerifyHistogramBucketBoundaries;
public int MeasurementCount => _values.Count;

public InstrumentRecorder(string instrumentName)
{
Expand Down Expand Up @@ -193,6 +195,13 @@ private void OnMeasurementRecorded(Instrument instrument, T measurement, ReadOnl
{
_values.Enqueue(new Measurement<T>(measurement, tags));
MeasurementRecorded?.Invoke();
if (VerifyHistogramBucketBoundaries is not null)
{
Histogram<T> histogram = (Histogram<T>)instrument;
IReadOnlyList<T> boundaries = histogram.Advice.HistogramBucketBoundaries;
Assert.NotNull(boundaries);
VerifyHistogramBucketBoundaries(boundaries);
}
}

public IReadOnlyList<Measurement<T>> GetMeasurements() => _values.ToArray();
Expand Down Expand Up @@ -328,6 +337,7 @@ public Task RequestDuration_Success_Recorded(string method, HttpStatusCode statu
{
using HttpMessageInvoker client = CreateHttpMessageInvoker();
using InstrumentRecorder<double> recorder = SetupInstrumentRecorder<double>(InstrumentNames.RequestDuration);

using HttpRequestMessage request = new(HttpMethod.Parse(method), uri) { Version = UseVersion };

using HttpResponseMessage response = await SendAsync(client, request);
Expand Down Expand Up @@ -916,6 +926,40 @@ await IgnoreExceptions(async () =>
});
});
}

[Fact]
public Task DurationHistograms_HaveBucketSizeHints()
{
return LoopbackServerFactory.CreateClientAndServerAsync(async uri =>
{
using HttpMessageInvoker client = CreateHttpMessageInvoker();
using InstrumentRecorder<double> requestDurationRecorder = SetupInstrumentRecorder<double>(InstrumentNames.RequestDuration);
using InstrumentRecorder<double> timeInQueueRecorder = SetupInstrumentRecorder<double>(InstrumentNames.TimeInQueue);
using InstrumentRecorder<double> connectionDurationRecorder = SetupInstrumentRecorder<double>(InstrumentNames.ConnectionDuration);

requestDurationRecorder.VerifyHistogramBucketBoundaries = b =>
{
// Verify first and last value of the boundaries defined in
// https://github.com/open-telemetry/semantic-conventions/blob/release/v1.23.x/docs/http/http-metrics.md#metric-httpserverrequestduration
Assert.Equal(0.005, b.First());
Assert.Equal(10, b.Last());
};
timeInQueueRecorder.VerifyHistogramBucketBoundaries = requestDurationRecorder.VerifyHistogramBucketBoundaries;
connectionDurationRecorder.VerifyHistogramBucketBoundaries =
b => Assert.True(b.Last() > 180); // At least 3 minutes for the highest bucket.

using HttpRequestMessage request = new(HttpMethod.Get, uri) { Version = UseVersion };
using HttpResponseMessage response = await SendAsync(client, request);

Assert.Equal(1, requestDurationRecorder.MeasurementCount);
Assert.Equal(1, timeInQueueRecorder.MeasurementCount);
client.Dispose(); // terminate the connection
Assert.Equal(1, connectionDurationRecorder.MeasurementCount);
}, async server =>
{
await server.AcceptConnectionSendResponseAndCloseAsync();
});
}
}

[ActiveIssue("https://github.com/dotnet/runtime/issues/93754", TestPlatforms.Browser)]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,14 @@ internal static class NameResolutionMetrics
private static readonly Histogram<double> s_lookupDuration = s_meter.CreateHistogram<double>(
name: "dns.lookup.duration",
unit: "s",
description: "Measures the time taken to perform a DNS lookup.");
description: "Measures the time taken to perform a DNS lookup.",
advice: new InstrumentAdvice<double>()
{
// OTel bucket boundary recommendation for 'http.request.duration':
// https://github.com/open-telemetry/semantic-conventions/blob/release/v1.23.x/docs/http/http-metrics.md#metric-httpclientrequestduration
// We are using these boundaries for all network requests that are expected to be short.
HistogramBucketBoundaries = [0.005, 0.01, 0.025, 0.05, 0.075, 0.1, 0.25, 0.5, 0.75, 1, 2.5, 5, 7.5, 10]
});

public static bool IsEnabled() => s_lookupDuration.Enabled;

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,22 @@ await RemoteExecutor.Invoke(async () =>
}).DisposeAsync();
}

[Fact]
public static async Task DurationHistogram_HasBucketSizeHints()
{
await RemoteExecutor.Invoke(async () =>
{
const string ValidHostName = "localhost";

using var recorder = new InstrumentRecorder<double>(DnsLookupDuration);
recorder.VerifyHistogramBucketBoundaries = b => Assert.True(b.Count > 2);

await Dns.GetHostEntryAsync(ValidHostName);

Assert.Equal(1, recorder.MeasurementCount);
}).DisposeAsync();
}

[Fact]
public static async Task ResolveInvalidHostName_MetricsRecorded()
{
Expand Down Expand Up @@ -86,6 +102,9 @@ private sealed class InstrumentRecorder<T> : IDisposable where T : struct
private readonly MeterListener _meterListener = new();
private readonly ConcurrentQueue<Measurement<T>> _values = new();

public Action<IReadOnlyList<T>> VerifyHistogramBucketBoundaries;
public int MeasurementCount => _values.Count;

public InstrumentRecorder(string instrumentName)
{
_meterListener.InstrumentPublished = (instrument, listener) =>
Expand All @@ -99,7 +118,17 @@ public InstrumentRecorder(string instrumentName)
_meterListener.Start();
}

private void OnMeasurementRecorded(Instrument instrument, T measurement, ReadOnlySpan<KeyValuePair<string, object?>> tags, object? state) => _values.Enqueue(new Measurement<T>(measurement, tags));
private void OnMeasurementRecorded(Instrument instrument, T measurement, ReadOnlySpan<KeyValuePair<string, object?>> tags, object? state)
{
_values.Enqueue(new Measurement<T>(measurement, tags));
if (VerifyHistogramBucketBoundaries is not null)
{
Histogram<T> histogram = (Histogram<T>)instrument;
IReadOnlyList<T> boundaries = histogram.Advice.HistogramBucketBoundaries;
Assert.NotNull(boundaries);
VerifyHistogramBucketBoundaries(boundaries);
}
}
public IReadOnlyList<Measurement<T>> GetMeasurements() => _values.ToArray();
public void Dispose() => _meterListener.Dispose();
}
Expand Down
Loading