diff --git a/src/OpenTelemetry.Instrumentation.AspNetCore/CHANGELOG.md b/src/OpenTelemetry.Instrumentation.AspNetCore/CHANGELOG.md index b44b5fb8b1e..667624a692f 100644 --- a/src/OpenTelemetry.Instrumentation.AspNetCore/CHANGELOG.md +++ b/src/OpenTelemetry.Instrumentation.AspNetCore/CHANGELOG.md @@ -2,6 +2,13 @@ ## Unreleased +* **Breaking change** The metric `http.server.duration` has been updated to the + latest spec for [metrics](https://github.com/open-telemetry/semantic-conventions/blob/v1.22.0/docs/http/http-metrics.md). + Implemented new histogram `http.server.request.duration` to replace + `http.server.duration`. New histogram records seconds and has updated histogram + bounds. + ([#4766](https://github.com/open-telemetry/opentelemetry-dotnet/pull/4766)) + ## 1.5.1-beta.1 Released 2023-Jul-20 diff --git a/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInMetricsListener.cs b/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInMetricsListener.cs index ce06402bc34..54387869b3e 100644 --- a/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInMetricsListener.cs +++ b/src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInMetricsListener.cs @@ -27,13 +27,19 @@ namespace OpenTelemetry.Instrumentation.AspNetCore.Implementation; internal sealed class HttpInMetricsListener : ListenerHandler { - private const string HttpServerDurationMetricName = "http.server.duration"; + internal const string HttpServerDurationMetricName = "http.server.duration"; + internal const string HttpServerRequestDurationMetricName = "http.server.request.duration"; + + // Http Metrics use custom histogram boundaries. See the spec: https://github.com/open-telemetry/semantic-conventions/blob/v1.21.0/docs/http/http-metrics.md + internal static double[] HttpServerDurationMetricExplicitBounds = new double[] { 0, 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 }; + private const string OnStopEvent = "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop"; private const string EventName = "OnStopActivity"; private readonly Meter meter; private readonly AspNetCoreMetricsInstrumentationOptions options; private readonly Histogram httpServerDuration; + private readonly Histogram httpServerRequestDuration; private readonly bool emitOldAttributes; private readonly bool emitNewAttributes; @@ -43,6 +49,7 @@ internal HttpInMetricsListener(string name, Meter meter, AspNetCoreMetricsInstru this.meter = meter; this.options = options; this.httpServerDuration = meter.CreateHistogram(HttpServerDurationMetricName, "ms", "Measures the duration of inbound HTTP requests."); + this.httpServerRequestDuration = meter.CreateHistogram(HttpServerRequestDurationMetricName, "s", "Measures the duration of inbound HTTP requests."); this.emitOldAttributes = this.options.HttpSemanticConvention.HasFlag(HttpSemanticConvention.Old); @@ -144,7 +151,15 @@ public override void OnEventWritten(string name, object payload) // We are relying here on ASP.NET Core to set duration before writing the stop event. // https://github.com/dotnet/aspnetcore/blob/d6fa351048617ae1c8b47493ba1abbe94c3a24cf/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs#L449 // TODO: Follow up with .NET team if we can continue to rely on this behavior. - this.httpServerDuration.Record(Activity.Current.Duration.TotalMilliseconds, tags); + if (this.emitNewAttributes) + { + this.httpServerRequestDuration.Record(Activity.Current.Duration.TotalSeconds, tags); + } + + if (this.emitOldAttributes) + { + this.httpServerDuration.Record(Activity.Current.Duration.TotalMilliseconds, tags); + } } } } diff --git a/src/OpenTelemetry.Instrumentation.AspNetCore/MeterProviderBuilderExtensions.cs b/src/OpenTelemetry.Instrumentation.AspNetCore/MeterProviderBuilderExtensions.cs index 99330ac220a..e78aa966534 100644 --- a/src/OpenTelemetry.Instrumentation.AspNetCore/MeterProviderBuilderExtensions.cs +++ b/src/OpenTelemetry.Instrumentation.AspNetCore/MeterProviderBuilderExtensions.cs @@ -14,11 +14,13 @@ // limitations under the License. // +using Microsoft.Extensions.Configuration; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Options; using OpenTelemetry.Instrumentation.AspNetCore; using OpenTelemetry.Instrumentation.AspNetCore.Implementation; using OpenTelemetry.Internal; +using static OpenTelemetry.Internal.HttpSemanticConventionHelper; namespace OpenTelemetry.Metrics; @@ -78,6 +80,18 @@ public static MeterProviderBuilder AddAspNetCoreInstrumentation( builder.AddMeter(AspNetCoreMetrics.InstrumentationName); + var configuration = new ConfigurationBuilder().AddEnvironmentVariables().Build(); + var httpSemanticConvention = GetSemanticConventionOptIn(configuration); + if (httpSemanticConvention.HasFlag(HttpSemanticConvention.New)) + { + // THIS IS A HACK. + // TODO: REMOVE VIEW AND USE HINT API WHEN AVAILABLE. + // https://github.com/open-telemetry/opentelemetry-dotnet/pull/4766#discussion_r1291903760 + builder.AddView( + instrumentName: HttpInMetricsListener.HttpServerRequestDurationMetricName, + metricStreamConfiguration: new ExplicitBucketHistogramConfiguration { Boundaries = HttpInMetricsListener.HttpServerDurationMetricExplicitBounds }); + } + builder.AddInstrumentation(sp => { var options = sp.GetRequiredService>().Get(name); diff --git a/src/OpenTelemetry.Instrumentation.AspNetCore/README.md b/src/OpenTelemetry.Instrumentation.AspNetCore/README.md index 131f98a4b37..7c0c33d59eb 100644 --- a/src/OpenTelemetry.Instrumentation.AspNetCore/README.md +++ b/src/OpenTelemetry.Instrumentation.AspNetCore/README.md @@ -91,12 +91,12 @@ public void ConfigureServices(IServiceCollection services) #### List of metrics produced The instrumentation is implemented based on [metrics semantic -conventions](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/metrics/semantic_conventions/http-metrics.md#metric-httpserverduration). +conventions](https://github.com/open-telemetry/semantic-conventions/blob/v1.21.0/docs/http/http-metrics.md#metric-httpserverduration). Currently, the instrumentation supports the following metric. | Name | Instrument Type | Unit | Description | |-------|-----------------|------|-------------| -| `http.server.duration` | Histogram | `ms` | Measures the duration of inbound HTTP requests. | +| `http.server.duration` | Histogram | `s` | Measures the duration of inbound HTTP requests. | ## Advanced configuration diff --git a/test/OpenTelemetry.Instrumentation.AspNetCore.Tests/MetricTests.cs b/test/OpenTelemetry.Instrumentation.AspNetCore.Tests/MetricTests.cs index 607472c83a4..957fcd8b1dc 100644 --- a/test/OpenTelemetry.Instrumentation.AspNetCore.Tests/MetricTests.cs +++ b/test/OpenTelemetry.Instrumentation.AspNetCore.Tests/MetricTests.cs @@ -30,6 +30,8 @@ namespace OpenTelemetry.Instrumentation.AspNetCore.Tests; public class MetricTests : IClassFixture>, IDisposable { + public const string SemanticConventionOptInKeyName = "OTEL_SEMCONV_STABILITY_OPT_IN"; + private const int StandardTagsCount = 6; private readonly WebApplicationFactory factory; @@ -47,47 +49,78 @@ public void AddAspNetCoreInstrumentation_BadArgs() Assert.Throws(() => builder.AddAspNetCoreInstrumentation()); } - [Fact] - public async Task RequestMetricIsCaptured() + [Theory] + [InlineData(null, true, false, 6)] // emits old metric & attributes + [InlineData("http", false, true, 6)] // emits new metric & attributes + [InlineData("http/dup", true, true, 11)] // emits both old & new + public async Task RequestMetricIsCaptured(string environmentVarValue, bool validateOldSemConv, bool validateNewSemConv, int expectedTagsCount) { - var metricItems = new List(); + try + { + Environment.SetEnvironmentVariable(SemanticConventionOptInKeyName, environmentVarValue); - this.meterProvider = Sdk.CreateMeterProviderBuilder() - .AddAspNetCoreInstrumentation() - .AddInMemoryExporter(metricItems) - .Build(); + var metricItems = new List(); - using (var client = this.factory - .WithWebHostBuilder(builder => + this.meterProvider = Sdk.CreateMeterProviderBuilder() + .AddAspNetCoreInstrumentation() + .AddInMemoryExporter(metricItems) + .Build(); + + using (var client = this.factory + .WithWebHostBuilder(builder => + { + builder.ConfigureLogging(loggingBuilder => loggingBuilder.ClearProviders()); + }) + .CreateClient()) { - builder.ConfigureLogging(loggingBuilder => loggingBuilder.ClearProviders()); - }) - .CreateClient()) - { - using var response1 = await client.GetAsync("/api/values").ConfigureAwait(false); - using var response2 = await client.GetAsync("/api/values/2").ConfigureAwait(false); + using var response1 = await client.GetAsync("/api/values").ConfigureAwait(false); + using var response2 = await client.GetAsync("/api/values/2").ConfigureAwait(false); - response1.EnsureSuccessStatusCode(); - response2.EnsureSuccessStatusCode(); - } + response1.EnsureSuccessStatusCode(); + response2.EnsureSuccessStatusCode(); + } - // We need to let End callback execute as it is executed AFTER response was returned. - // In unit tests environment there may be a lot of parallel unit tests executed, so - // giving some breezing room for the End callback to complete - await Task.Delay(TimeSpan.FromSeconds(1)).ConfigureAwait(false); + // We need to let End callback execute as it is executed AFTER response was returned. + // In unit tests environment there may be a lot of parallel unit tests executed, so + // giving some breezing room for the End callback to complete + await Task.Delay(TimeSpan.FromSeconds(1)).ConfigureAwait(false); - this.meterProvider.Dispose(); + this.meterProvider.Dispose(); - var requestMetrics = metricItems - .Where(item => item.Name == "http.server.duration") - .ToArray(); + if (validateOldSemConv) + { + var requestMetrics = metricItems + .Where(item => item.Name == "http.server.duration") + .ToArray(); - var metric = Assert.Single(requestMetrics); - var metricPoints = GetMetricPoints(metric); - Assert.Equal(2, metricPoints.Count); + var metric = Assert.Single(requestMetrics); + Assert.Equal("ms", metric.Unit); + var metricPoints = GetMetricPoints(metric); + Assert.Equal(2, metricPoints.Count); - AssertMetricPoint(metricPoints[0], expectedRoute: "api/Values"); - AssertMetricPoint(metricPoints[1], expectedRoute: "api/Values/{id}"); + AssertMetricPoint(metricPoints[0], expectedRoute: "api/Values", expectedTagsCount: expectedTagsCount, validateOldSemConv: true); + AssertMetricPoint(metricPoints[1], expectedRoute: "api/Values/{id}", expectedTagsCount: expectedTagsCount, validateOldSemConv: true); + } + + if (validateNewSemConv) + { + var requestMetrics = metricItems + .Where(item => item.Name == "http.server.request.duration") + .ToArray(); + + var metric = Assert.Single(requestMetrics); + Assert.Equal("s", metric.Unit); + var metricPoints = GetMetricPoints(metric); + Assert.Equal(2, metricPoints.Count); + + AssertMetricPoint(metricPoints[0], expectedRoute: "api/Values", expectedTagsCount: expectedTagsCount, validateNewSemConv: true); + AssertMetricPoint(metricPoints[1], expectedRoute: "api/Values/{id}", expectedTagsCount: expectedTagsCount, validateNewSemConv: true); + } + } + finally + { + Environment.SetEnvironmentVariable(SemanticConventionOptInKeyName, null); + } } [Fact] @@ -133,7 +166,7 @@ void ConfigureTestServices(IServiceCollection services) // Assert single because we filtered out one route var metricPoint = Assert.Single(GetMetricPoints(metric)); - AssertMetricPoint(metricPoint); + AssertMetricPoint(metricPoint, validateOldSemConv: true); } [Fact] @@ -187,7 +220,7 @@ void ConfigureTestServices(IServiceCollection services) var metric = Assert.Single(requestMetrics); var metricPoint = Assert.Single(GetMetricPoints(metric)); - var tags = AssertMetricPoint(metricPoint, expectedTagsCount: StandardTagsCount + 2); + var tags = AssertMetricPoint(metricPoint, expectedTagsCount: StandardTagsCount + 2, validateOldSemConv: true); Assert.Contains(tagsToAdd[0], tags); Assert.Contains(tagsToAdd[1], tags); @@ -215,7 +248,9 @@ private static List GetMetricPoints(Metric metric) private static KeyValuePair[] AssertMetricPoint( MetricPoint metricPoint, string expectedRoute = "api/Values", - int expectedTagsCount = StandardTagsCount) + int expectedTagsCount = StandardTagsCount, + bool validateNewSemConv = false, + bool validateOldSemConv = false) { var count = metricPoint.GetHistogramCount(); var sum = metricPoint.GetHistogramSum(); @@ -230,20 +265,63 @@ private static KeyValuePair[] AssertMetricPoint( attributes[i++] = tag; } - var method = new KeyValuePair(SemanticConventions.AttributeHttpMethod, "GET"); - var scheme = new KeyValuePair(SemanticConventions.AttributeHttpScheme, "http"); - var statusCode = new KeyValuePair(SemanticConventions.AttributeHttpStatusCode, 200); - var flavor = new KeyValuePair(SemanticConventions.AttributeHttpFlavor, "1.1"); - var host = new KeyValuePair(SemanticConventions.AttributeNetHostName, "localhost"); - var route = new KeyValuePair(SemanticConventions.AttributeHttpRoute, expectedRoute); - Assert.Contains(method, attributes); - Assert.Contains(scheme, attributes); - Assert.Contains(statusCode, attributes); - Assert.Contains(flavor, attributes); - Assert.Contains(host, attributes); - Assert.Contains(route, attributes); + // Inspect Attributes Assert.Equal(expectedTagsCount, attributes.Length); + if (validateNewSemConv) + { + var method = new KeyValuePair(SemanticConventions.AttributeHttpRequestMethod, "GET"); + var scheme = new KeyValuePair(SemanticConventions.AttributeUrlScheme, "http"); + var statusCode = new KeyValuePair(SemanticConventions.AttributeHttpResponseStatusCode, 200); + var flavor = new KeyValuePair(SemanticConventions.AttributeNetworkProtocolVersion, "1.1"); + var host = new KeyValuePair(SemanticConventions.AttributeServerAddress, "localhost"); + var route = new KeyValuePair(SemanticConventions.AttributeHttpRoute, expectedRoute); + Assert.Contains(method, attributes); + Assert.Contains(scheme, attributes); + Assert.Contains(statusCode, attributes); + Assert.Contains(flavor, attributes); + Assert.Contains(host, attributes); + Assert.Contains(route, attributes); + } + + if (validateOldSemConv) + { + var method = new KeyValuePair(SemanticConventions.AttributeHttpMethod, "GET"); + var scheme = new KeyValuePair(SemanticConventions.AttributeHttpScheme, "http"); + var statusCode = new KeyValuePair(SemanticConventions.AttributeHttpStatusCode, 200); + var flavor = new KeyValuePair(SemanticConventions.AttributeHttpFlavor, "1.1"); + var host = new KeyValuePair(SemanticConventions.AttributeNetHostName, "localhost"); + var route = new KeyValuePair(SemanticConventions.AttributeHttpRoute, expectedRoute); + Assert.Contains(method, attributes); + Assert.Contains(scheme, attributes); + Assert.Contains(statusCode, attributes); + Assert.Contains(flavor, attributes); + Assert.Contains(host, attributes); + Assert.Contains(route, attributes); + } + + // Inspect Histogram Bounds + var histogramBuckets = metricPoint.GetHistogramBuckets(); + var histogramBounds = new List(); + foreach (var t in histogramBuckets) + { + histogramBounds.Add(t.ExplicitBound); + } + + if (validateNewSemConv) + { + Assert.Equal( + expected: new List { 0, 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, double.PositiveInfinity }, + actual: histogramBounds); + } + + if (validateOldSemConv) + { + Assert.Equal( + expected: new List { 0, 5, 10, 25, 50, 75, 100, 250, 500, 750, 1000, 2500, 5000, 7500, 10000, double.PositiveInfinity }, + actual: histogramBounds); + } + return attributes; } }