Skip to content

Commit

Permalink
Add bucket bound hints to Networking histograms (dotnet#104629)
Browse files Browse the repository at this point in the history
Fixes dotnet#104137.

HistogramBucketBoundaries is a new feature added in dotnet#63650. As described in dotnet#104137, adding support helps removing a workaround in the otel SDK, and also might help users who do not use the SDK.
  • Loading branch information
antonfirsov authored Jul 10, 2024
1 parent aed5c22 commit 5f9fff0
Show file tree
Hide file tree
Showing 6 changed files with 101 additions and 5 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -3,12 +3,21 @@

using System.Collections.Generic;
using System.Diagnostics;
using System.Diagnostics.Metrics;
using System.Threading;

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 the same boundaries for durations which are not expected to be longer than an HTTP request.
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]
};

internal static string GetRedactedUriString(Uri uri)
{
Debug.Assert(uri.IsAbsoluteUri);
Expand Down
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 @@ -172,6 +172,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 @@ -204,6 +206,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 @@ -339,6 +348,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 @@ -927,6 +937,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

0 comments on commit 5f9fff0

Please sign in to comment.