From 5f851a9db8e2f484f48fa3598d047efbfb34d000 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Thu, 13 Apr 2023 08:29:07 +0800 Subject: [PATCH 1/6] WIP --- .../src/Internal/HostingApplication.cs | 7 ++- .../Internal/HostingApplicationDiagnostics.cs | 6 +-- .../Hosting/src/Internal/HostingMetrics.cs | 26 ++++++++-- .../src/Internal/HttpMetricsTagsFeature.cs | 4 +- .../Hosting/test/HostingApplicationTests.cs | 49 ++++++++++++++++++- .../Infrastructure/KestrelConnectionOfT.cs | 20 +++++--- .../Internal/Infrastructure/KestrelMetrics.cs | 28 ++++++++--- 7 files changed, 112 insertions(+), 28 deletions(-) diff --git a/src/Hosting/Hosting/src/Internal/HostingApplication.cs b/src/Hosting/Hosting/src/Internal/HostingApplication.cs index b880a7d3106b..2b7470556997 100644 --- a/src/Hosting/Hosting/src/Internal/HostingApplication.cs +++ b/src/Hosting/Hosting/src/Internal/HostingApplication.cs @@ -129,7 +129,10 @@ public Activity? Activity { if (HttpActivityFeature is null) { - HttpActivityFeature = new ActivityFeature(value!); + if (value != null) + { + HttpActivityFeature = new ActivityFeature(value); + } } else { @@ -144,7 +147,7 @@ public Activity? Activity public bool EventLogOrMetricsEnabled { get; set; } internal IHttpActivityFeature? HttpActivityFeature; - internal HttpMetricsTagsFeature? MetricsTagsFeature; + internal IHttpMetricsTagsFeature? MetricsTagsFeature; public void Reset() { diff --git a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs index fb24de39de1c..b9bfbea784cd 100644 --- a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs @@ -55,14 +55,14 @@ public void BeginRequest(HttpContext httpContext, HostingApplication.Context con if (_eventSource.IsEnabled() || _metrics.IsEnabled()) { context.EventLogOrMetricsEnabled = true; - if (httpContext.Features.Get() is HttpMetricsTagsFeature feature) + if (httpContext.Features.Get() is IHttpMetricsTagsFeature feature) { context.MetricsTagsFeature = feature; } else { context.MetricsTagsFeature ??= new HttpMetricsTagsFeature(); - httpContext.Features.Set(context.MetricsTagsFeature); + httpContext.Features.Set(context.MetricsTagsFeature); } startTimestamp = Stopwatch.GetTimestamp(); @@ -146,7 +146,7 @@ public void RequestEnd(HttpContext httpContext, Exception? exception, HostingApp if (context.EventLogOrMetricsEnabled) { var route = httpContext.GetEndpoint()?.Metadata.GetMetadata()?.Route; - var customTags = context.MetricsTagsFeature?.TagsList; + var customTags = context.MetricsTagsFeature?.Tags; _metrics.RequestEnd( httpContext.Request.Protocol, diff --git a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs index 87d3ddf796e5..5167daf878f2 100644 --- a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs @@ -40,7 +40,7 @@ public void RequestStart(bool isHttps, string scheme, string method, HostString _currentRequestsCounter.Add(1, tags); } - public void RequestEnd(string protocol, bool isHttps, string scheme, string method, HostString host, string? route, int statusCode, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) + public void RequestEnd(string protocol, bool isHttps, string scheme, string method, HostString host, string? route, int statusCode, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) { var tags = new TagList(); InitializeRequestTags(ref tags, isHttps, scheme, method, host); @@ -69,10 +69,7 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth } if (customTags != null) { - for (var i = 0; i < customTags.Count; i++) - { - tags.Add(customTags[i]); - } + AddCustomTags(ref tags, customTags); } var duration = Stopwatch.GetElapsedTime(startTimestamp, currentTimestamp); @@ -80,6 +77,25 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth } } + private static void AddCustomTags(ref TagList tags, ICollection> customTags) + { + // Skip allocating enumerator if tags collection is a list. + if (customTags is List> list) + { + for (var i = 0; i < list.Count; i++) + { + tags.Add(list[i]); + } + } + else + { + foreach (var tag in customTags) + { + tags.Add(tag); + } + } + } + public void Dispose() { _meter.Dispose(); diff --git a/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs b/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs index 9b11265e5db2..45eb35845854 100644 --- a/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs +++ b/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs @@ -7,7 +7,5 @@ namespace Microsoft.AspNetCore.Hosting; internal sealed class HttpMetricsTagsFeature : IHttpMetricsTagsFeature { - public ICollection> Tags => TagsList; - - public List> TagsList { get; } = new List>(); + public ICollection> Tags { get; } = new List>(); } diff --git a/src/Hosting/Hosting/test/HostingApplicationTests.cs b/src/Hosting/Hosting/test/HostingApplicationTests.cs index a0154713d137..1ab0021f73bb 100644 --- a/src/Hosting/Hosting/test/HostingApplicationTests.cs +++ b/src/Hosting/Hosting/test/HostingApplicationTests.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. using System.Collections; +using System.Collections.ObjectModel; using System.Diagnostics; using System.Diagnostics.Metrics; using Microsoft.AspNetCore.Hosting.Fakes; @@ -108,6 +109,46 @@ static void AssertRequestDuration(Measurement measurement, string protoc } } + [Fact] + public void MetricsFeatureUsedFromFeatureCollection() + { + // Arrange + var meterFactory = new TestMeterFactory(); + var meterRegistry = new TestMeterRegistry(meterFactory.Meters); + var hostingApplication = CreateApplication(meterFactory: meterFactory); + var httpContext = new DefaultHttpContext(); + var meter = meterFactory.Meters.Single(); + + using var requestDurationRecorder = new InstrumentRecorder(meterRegistry, HostingMetrics.MeterName, "request-duration"); + using var currentRequestsRecorder = new InstrumentRecorder(meterRegistry, HostingMetrics.MeterName, "current-requests"); + + // Act/Assert + Assert.Equal(HostingMetrics.MeterName, meter.Name); + Assert.Null(meter.Version); + + var feature = new TestHttpMetricsTagsFeature(); + feature.Tags.Add(new KeyValuePair("test", "Value!")); + httpContext.Features.Set(feature); + var context1 = hostingApplication.CreateContext(httpContext.Features); + context1.HttpContext.Response.StatusCode = StatusCodes.Status200OK; + hostingApplication.DisposeContext(context1, null); + + Assert.Collection(currentRequestsRecorder.GetMeasurements(), + m => Assert.Equal(1, m.Value), + m => Assert.Equal(-1, m.Value)); + Assert.Collection(requestDurationRecorder.GetMeasurements(), + m => + { + Assert.True(m.Value > 0); + Assert.Equal("Value!", (string)m.Tags.ToArray().Single(t => t.Key == "test").Value); + }); + } + + private class TestHttpMetricsTagsFeature : IHttpMetricsTagsFeature + { + public ICollection> Tags { get; } = new Collection>(); + } + [Fact] public void DisposeContextDoesNotClearHttpContextIfDefaultHttpContextFactoryUsed() { @@ -204,7 +245,9 @@ public void IHttpActivityFeatureIsPopulated() var initialActivity = Activity.Current; // Create nested dummy Activity - using var _ = dummySource.StartActivity("DummyActivity"); + using var dummyActivity = dummySource.StartActivity("DummyActivity"); + Assert.NotNull(dummyActivity); + Assert.Equal(Activity.Current, dummyActivity); Assert.Same(initialActivity, activityFeature.Activity); Assert.Null(activityFeature.Activity.ParentId); @@ -247,7 +290,9 @@ public void IHttpActivityFeatureIsAssignedToIfItExists() var initialActivity = Activity.Current; // Create nested dummy Activity - using var _ = dummySource.StartActivity("DummyActivity"); + using var dummyActivity = dummySource.StartActivity("DummyActivity"); + Assert.NotNull(dummyActivity); + Assert.Equal(Activity.Current, dummyActivity); Assert.Same(initialActivity, activityFeature.Activity); Assert.Null(activityFeature.Activity.ParentId); diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs index 22c84ae704ce..640e9e06e0a2 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs @@ -40,15 +40,22 @@ internal async Task ExecuteAsync() var connectionContext = _transportConnection; var metricsConnectionDurationEnabled = _serviceContext.Metrics.IsConnectionDurationEnabled(); var startTimestamp = 0L; - ConnectionMetricsTagsFeature? metricsTagsFeature = null; + IConnectionMetricsTagsFeature? metricsTagsFeature = null; Exception? unhandledException = null; if (metricsConnectionDurationEnabled) { - startTimestamp = Stopwatch.GetTimestamp(); + if (connectionContext.Features.Get() is IConnectionMetricsTagsFeature feature) + { + metricsTagsFeature = feature; + } + else + { + metricsTagsFeature = new ConnectionMetricsTagsFeature(); + connectionContext.Features.Set(metricsTagsFeature); + } - metricsTagsFeature = new ConnectionMetricsTagsFeature(); - connectionContext.Features.Set(metricsTagsFeature); + startTimestamp = Stopwatch.GetTimestamp(); } try @@ -85,7 +92,7 @@ internal async Task ExecuteAsync() Logger.ConnectionStop(connectionContext.ConnectionId); KestrelEventSource.Log.ConnectionStop(connectionContext); - _serviceContext.Metrics.ConnectionStop(connectionContext, unhandledException, metricsTagsFeature?.TagsList, startTimestamp, currentTimestamp); + _serviceContext.Metrics.ConnectionStop(connectionContext, unhandledException, metricsTagsFeature?.Tags, startTimestamp, currentTimestamp); // Dispose the transport connection, this needs to happen before removing it from the // connection manager so that we only signal completion of this connection after the transport @@ -98,7 +105,6 @@ internal async Task ExecuteAsync() private sealed class ConnectionMetricsTagsFeature : IConnectionMetricsTagsFeature { - public ICollection> Tags => TagsList; - public List> TagsList { get; } = new List>(); + public ICollection> Tags { get; } = new List>(); } } diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs index 9bd1ab2a5969..a3b9ef57331a 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs @@ -80,7 +80,7 @@ private void ConnectionStartCore(BaseConnectionContext connection) _currentConnectionsCounter.Add(1, tags); } - public void ConnectionStop(BaseConnectionContext connection, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) + public void ConnectionStop(BaseConnectionContext connection, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) { if (_currentConnectionsCounter.Enabled || _connectionDuration.Enabled) { @@ -89,7 +89,7 @@ public void ConnectionStop(BaseConnectionContext connection, Exception? exceptio } [MethodImpl(MethodImplOptions.NoInlining)] - private void ConnectionStopCore(BaseConnectionContext connection, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) + private void ConnectionStopCore(BaseConnectionContext connection, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) { var tags = new TagList(); InitializeConnectionTags(ref tags, connection); @@ -105,16 +105,32 @@ private void ConnectionStopCore(BaseConnectionContext connection, Exception? exc // Add custom tags for duration. if (customTags != null) { - for (var i = 0; i < customTags.Count; i++) - { - tags.Add(customTags[i]); - } + AddCustomTags(ref tags, customTags); } var duration = Stopwatch.GetElapsedTime(startTimestamp, currentTimestamp); _connectionDuration.Record(duration.TotalSeconds, tags); } + private static void AddCustomTags(ref TagList tags, ICollection> customTags) + { + // Skip allocating enumerator if tags collection is a list. + if (customTags is List> list) + { + for (var i = 0; i < list.Count; i++) + { + tags.Add(list[i]); + } + } + else + { + foreach (var tag in customTags) + { + tags.Add(tag); + } + } + } + public void ConnectionRejected(BaseConnectionContext connection) { if (_rejectedConnectionsCounter.Enabled) From 95e44b8474351fdadd8279aaa732aea35cac2609 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Thu, 13 Apr 2023 10:59:03 +0800 Subject: [PATCH 2/6] Update --- .../src/Internal/HostingApplication.cs | 6 +- .../Internal/HostingApplicationDiagnostics.cs | 22 +---- ...ivityFeature.cs => HttpActivityFeature.cs} | 4 +- .../Hosting/test/HostingApplicationTests.cs | 57 +++++-------- .../Infrastructure/KestrelConnectionOfT.cs | 11 +-- .../KestrelMetricsTests.cs | 80 +++++++++++++++++++ .../TestTransport/TestServer.cs | 5 +- 7 files changed, 115 insertions(+), 70 deletions(-) rename src/Hosting/Hosting/src/Internal/{ActivityFeature.cs => HttpActivityFeature.cs} (79%) diff --git a/src/Hosting/Hosting/src/Internal/HostingApplication.cs b/src/Hosting/Hosting/src/Internal/HostingApplication.cs index 2b7470556997..b94f2e9b8b89 100644 --- a/src/Hosting/Hosting/src/Internal/HostingApplication.cs +++ b/src/Hosting/Hosting/src/Internal/HostingApplication.cs @@ -131,7 +131,7 @@ public Activity? Activity { if (value != null) { - HttpActivityFeature = new ActivityFeature(value); + HttpActivityFeature = new HttpActivityFeature(value); } } else @@ -146,8 +146,8 @@ public Activity? Activity internal bool HasDiagnosticListener { get; set; } public bool EventLogOrMetricsEnabled { get; set; } - internal IHttpActivityFeature? HttpActivityFeature; - internal IHttpMetricsTagsFeature? MetricsTagsFeature; + internal HttpActivityFeature? HttpActivityFeature; + internal HttpMetricsTagsFeature? MetricsTagsFeature; public void Reset() { diff --git a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs index b9bfbea784cd..ed63318c6fb5 100644 --- a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs @@ -55,15 +55,8 @@ public void BeginRequest(HttpContext httpContext, HostingApplication.Context con if (_eventSource.IsEnabled() || _metrics.IsEnabled()) { context.EventLogOrMetricsEnabled = true; - if (httpContext.Features.Get() is IHttpMetricsTagsFeature feature) - { - context.MetricsTagsFeature = feature; - } - else - { - context.MetricsTagsFeature ??= new HttpMetricsTagsFeature(); - httpContext.Features.Set(context.MetricsTagsFeature); - } + context.MetricsTagsFeature ??= new HttpMetricsTagsFeature(); + httpContext.Features.Set(context.MetricsTagsFeature); startTimestamp = Stopwatch.GetTimestamp(); @@ -80,16 +73,9 @@ public void BeginRequest(HttpContext httpContext, HostingApplication.Context con context.Activity = StartActivity(httpContext, loggingEnabled, diagnosticListenerActivityCreationEnabled, out var hasDiagnosticListener); context.HasDiagnosticListener = hasDiagnosticListener; - if (context.Activity is Activity activity) + if (context.Activity != null) { - if (httpContext.Features.Get() is IHttpActivityFeature feature) - { - feature.Activity = activity; - } - else - { - httpContext.Features.Set(context.HttpActivityFeature); - } + httpContext.Features.Set(context.HttpActivityFeature); } } diff --git a/src/Hosting/Hosting/src/Internal/ActivityFeature.cs b/src/Hosting/Hosting/src/Internal/HttpActivityFeature.cs similarity index 79% rename from src/Hosting/Hosting/src/Internal/ActivityFeature.cs rename to src/Hosting/Hosting/src/Internal/HttpActivityFeature.cs index f89495c78bc9..d7fd773fa8fc 100644 --- a/src/Hosting/Hosting/src/Internal/ActivityFeature.cs +++ b/src/Hosting/Hosting/src/Internal/HttpActivityFeature.cs @@ -9,9 +9,9 @@ namespace Microsoft.AspNetCore.Hosting; /// /// Default implementation for . /// -internal sealed class ActivityFeature : IHttpActivityFeature +internal sealed class HttpActivityFeature : IHttpActivityFeature { - internal ActivityFeature(Activity activity) + internal HttpActivityFeature(Activity activity) { Activity = activity; } diff --git a/src/Hosting/Hosting/test/HostingApplicationTests.cs b/src/Hosting/Hosting/test/HostingApplicationTests.cs index 1ab0021f73bb..d3e9e2623b09 100644 --- a/src/Hosting/Hosting/test/HostingApplicationTests.cs +++ b/src/Hosting/Hosting/test/HostingApplicationTests.cs @@ -110,7 +110,7 @@ static void AssertRequestDuration(Measurement measurement, string protoc } [Fact] - public void MetricsFeatureUsedFromFeatureCollection() + public void IHttpMetricsTagsFeatureNotUsedFromFeatureCollection() { // Arrange var meterFactory = new TestMeterFactory(); @@ -126,25 +126,18 @@ public void MetricsFeatureUsedFromFeatureCollection() Assert.Equal(HostingMetrics.MeterName, meter.Name); Assert.Null(meter.Version); - var feature = new TestHttpMetricsTagsFeature(); - feature.Tags.Add(new KeyValuePair("test", "Value!")); - httpContext.Features.Set(feature); - var context1 = hostingApplication.CreateContext(httpContext.Features); - context1.HttpContext.Response.StatusCode = StatusCodes.Status200OK; - hostingApplication.DisposeContext(context1, null); + // This feature will be overidden by hosting. Hosting is the owner of the feature and is resposible for setting it. + var overridenFeature = new TestHttpMetricsTagsFeature(); + httpContext.Features.Set(overridenFeature); - Assert.Collection(currentRequestsRecorder.GetMeasurements(), - m => Assert.Equal(1, m.Value), - m => Assert.Equal(-1, m.Value)); - Assert.Collection(requestDurationRecorder.GetMeasurements(), - m => - { - Assert.True(m.Value > 0); - Assert.Equal("Value!", (string)m.Tags.ToArray().Single(t => t.Key == "test").Value); - }); + var context = hostingApplication.CreateContext(httpContext.Features); + var contextFeature = httpContext.Features.Get(); + + Assert.NotNull(contextFeature); + Assert.NotEqual(overridenFeature, contextFeature); } - private class TestHttpMetricsTagsFeature : IHttpMetricsTagsFeature + private sealed class TestHttpMetricsTagsFeature : IHttpMetricsTagsFeature { public ICollection> Tags { get; } = new Collection>(); } @@ -264,8 +257,7 @@ private class TestHttpActivityFeature : IHttpActivityFeature } [Fact] - [QuarantinedTest("https://github.com/dotnet/aspnetcore/issues/38736")] - public void IHttpActivityFeatureIsAssignedToIfItExists() + public void IHttpActivityFeatureNotUsedFromFeatureCollection() { var testSource = new ActivitySource(Path.GetRandomFileName()); var dummySource = new ActivitySource(Path.GetRandomFileName()); @@ -279,28 +271,19 @@ public void IHttpActivityFeatureIsAssignedToIfItExists() var hostingApplication = CreateApplication(activitySource: testSource); var httpContext = new DefaultHttpContext(); - httpContext.Features.Set(new TestHttpActivityFeature()); - var context = hostingApplication.CreateContext(httpContext.Features); - var activityFeature = context.HttpContext.Features.Get(); - Assert.NotNull(activityFeature); - Assert.IsType(activityFeature); - Assert.NotNull(activityFeature.Activity); - Assert.Equal(HostingApplicationDiagnostics.ActivityName, activityFeature.Activity.DisplayName); - var initialActivity = Activity.Current; + // This feature will be overidden by hosting. Hosting is the owner of the feature and is resposible for setting it. + var overridenFeature = new TestHttpActivityFeature(); + httpContext.Features.Set(overridenFeature); - // Create nested dummy Activity - using var dummyActivity = dummySource.StartActivity("DummyActivity"); - Assert.NotNull(dummyActivity); - Assert.Equal(Activity.Current, dummyActivity); + var context = hostingApplication.CreateContext(httpContext.Features); - Assert.Same(initialActivity, activityFeature.Activity); - Assert.Null(activityFeature.Activity.ParentId); - Assert.Equal(activityFeature.Activity.Id, Activity.Current.ParentId); - Assert.NotEqual(Activity.Current, activityFeature.Activity); + var contextFeature = context.HttpContext.Features.Get(); + Assert.NotNull(contextFeature); + Assert.NotNull(contextFeature.Activity); + Assert.Equal(HostingApplicationDiagnostics.ActivityName, contextFeature.Activity.DisplayName); - // Act/Assert - hostingApplication.DisposeContext(context, null); + Assert.NotEqual(overridenFeature, contextFeature); } [Fact] diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs index 640e9e06e0a2..2c2eed275137 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs @@ -45,15 +45,8 @@ internal async Task ExecuteAsync() if (metricsConnectionDurationEnabled) { - if (connectionContext.Features.Get() is IConnectionMetricsTagsFeature feature) - { - metricsTagsFeature = feature; - } - else - { - metricsTagsFeature = new ConnectionMetricsTagsFeature(); - connectionContext.Features.Set(metricsTagsFeature); - } + metricsTagsFeature = new ConnectionMetricsTagsFeature(); + connectionContext.Features.Set(metricsTagsFeature); startTimestamp = Stopwatch.GetTimestamp(); } diff --git a/src/Servers/Kestrel/test/InMemory.FunctionalTests/KestrelMetricsTests.cs b/src/Servers/Kestrel/test/InMemory.FunctionalTests/KestrelMetricsTests.cs index 656b854bdc1f..b2b29966c1a9 100644 --- a/src/Servers/Kestrel/test/InMemory.FunctionalTests/KestrelMetricsTests.cs +++ b/src/Servers/Kestrel/test/InMemory.FunctionalTests/KestrelMetricsTests.cs @@ -88,6 +88,86 @@ await connection.ReceiveEnd( Assert.Collection(queuedConnections.GetMeasurements(), m => AssertCount(m, 1, "127.0.0.1:0"), m => AssertCount(m, -1, "127.0.0.1:0")); } + [Fact] + public async Task Http1Connection_IHttpConnectionTagsFeatureIgnoreFeatureSetOnTransport() + { + var sync = new SyncPoint(); + ConnectionContext currentConnectionContext = null; + + var listenOptions = new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)); + listenOptions.Use(next => + { + return async connectionContext => + { + currentConnectionContext = connectionContext; + + connectionContext.Features.Get().Tags.Add(new KeyValuePair("custom", "value!")); + + // Wait for the test to verify the connection has started. + await sync.WaitToContinue(); + + await next(connectionContext); + }; + }); + + var testMeterFactory = new TestMeterFactory(); + using var connectionDuration = new InstrumentRecorder(new TestMeterRegistry(testMeterFactory.Meters), "Microsoft.AspNetCore.Server.Kestrel", "connection-duration"); + using var currentConnections = new InstrumentRecorder(new TestMeterRegistry(testMeterFactory.Meters), "Microsoft.AspNetCore.Server.Kestrel", "current-connections"); + using var queuedConnections = new InstrumentRecorder(new TestMeterRegistry(testMeterFactory.Meters), "Microsoft.AspNetCore.Server.Kestrel", "queued-connections"); + + var serviceContext = new TestServiceContext(LoggerFactory, metrics: new KestrelMetrics(testMeterFactory)); + + var sendString = "POST / HTTP/1.0\r\nContent-Length: 12\r\n\r\nHello World?"; + + await using var server = new TestServer(EchoApp, serviceContext, listenOptions); + + // This feature will be overidden by Kestrel. Kestrel is the owner of the feature and is resposible for setting it. + var overridenFeature = new TestConnectionMetricsTagsFeature(); + overridenFeature.Tags.Add(new KeyValuePair("test", "Value!")); + + using (var connection = server.CreateConnection(featuresAction: features => + { + features.Set(overridenFeature); + })) + { + await connection.Send(sendString); + + // Wait for connection to start on the server. + await sync.WaitForSyncPoint(); + + Assert.NotEqual(overridenFeature, currentConnectionContext.Features.Get()); + + Assert.Empty(connectionDuration.GetMeasurements()); + Assert.Collection(currentConnections.GetMeasurements(), m => AssertCount(m, 1, "127.0.0.1:0")); + + // Signal that connection can continue. + sync.Continue(); + + await connection.ReceiveEnd( + "HTTP/1.1 200 OK", + "Connection: close", + $"Date: {serviceContext.DateHeaderValue}", + "", + "Hello World?"); + + await connection.WaitForConnectionClose(); + } + + Assert.Collection(connectionDuration.GetMeasurements(), m => + { + AssertDuration(m, "127.0.0.1:0"); + Assert.Equal("value!", (string)m.Tags.ToArray().Single(t => t.Key == "custom").Value); + Assert.Empty(m.Tags.ToArray().Where(t => t.Key == "test")); + }); + Assert.Collection(currentConnections.GetMeasurements(), m => AssertCount(m, 1, "127.0.0.1:0"), m => AssertCount(m, -1, "127.0.0.1:0")); + Assert.Collection(queuedConnections.GetMeasurements(), m => AssertCount(m, 1, "127.0.0.1:0"), m => AssertCount(m, -1, "127.0.0.1:0")); + } + + private sealed class TestConnectionMetricsTagsFeature : IConnectionMetricsTagsFeature + { + public ICollection> Tags { get; } = new List>(); + } + [Fact] public async Task Http1Connection_Error() { diff --git a/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/TestServer.cs b/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/TestServer.cs index ee9e1efa529d..976cb389131b 100644 --- a/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/TestServer.cs +++ b/src/Servers/Kestrel/test/InMemory.FunctionalTests/TestTransport/TestServer.cs @@ -16,6 +16,7 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Hosting.Server; using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; using Microsoft.AspNetCore.Testing; using Microsoft.Extensions.DependencyInjection; @@ -109,9 +110,11 @@ public TestServer(RequestDelegate app, TestServiceContext context, Action featuresAction = null) { var transportConnection = new InMemoryTransportConnection(_memoryPool, Context.Log, Context.Scheduler); + featuresAction?.Invoke(transportConnection.Features); + _transportFactory.AddConnection(transportConnection); return new InMemoryConnection(transportConnection, encoding); } From a50d1d0691eb5a5705cc2485cd0414b84e2f5021 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Thu, 13 Apr 2023 11:06:30 +0800 Subject: [PATCH 3/6] Clean up --- .../Internal/HostingApplicationDiagnostics.cs | 2 +- .../Hosting/src/Internal/HostingMetrics.cs | 26 ++++------------- .../src/Internal/HttpMetricsTagsFeature.cs | 4 ++- .../Infrastructure/KestrelConnectionOfT.cs | 8 ++++-- .../Internal/Infrastructure/KestrelMetrics.cs | 28 ++++--------------- 5 files changed, 20 insertions(+), 48 deletions(-) diff --git a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs index ed63318c6fb5..4d4c4a8a4a20 100644 --- a/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs @@ -132,7 +132,7 @@ public void RequestEnd(HttpContext httpContext, Exception? exception, HostingApp if (context.EventLogOrMetricsEnabled) { var route = httpContext.GetEndpoint()?.Metadata.GetMetadata()?.Route; - var customTags = context.MetricsTagsFeature?.Tags; + var customTags = context.MetricsTagsFeature?.TagsList; _metrics.RequestEnd( httpContext.Request.Protocol, diff --git a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs index 5167daf878f2..87d3ddf796e5 100644 --- a/src/Hosting/Hosting/src/Internal/HostingMetrics.cs +++ b/src/Hosting/Hosting/src/Internal/HostingMetrics.cs @@ -40,7 +40,7 @@ public void RequestStart(bool isHttps, string scheme, string method, HostString _currentRequestsCounter.Add(1, tags); } - public void RequestEnd(string protocol, bool isHttps, string scheme, string method, HostString host, string? route, int statusCode, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) + public void RequestEnd(string protocol, bool isHttps, string scheme, string method, HostString host, string? route, int statusCode, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) { var tags = new TagList(); InitializeRequestTags(ref tags, isHttps, scheme, method, host); @@ -69,7 +69,10 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth } if (customTags != null) { - AddCustomTags(ref tags, customTags); + for (var i = 0; i < customTags.Count; i++) + { + tags.Add(customTags[i]); + } } var duration = Stopwatch.GetElapsedTime(startTimestamp, currentTimestamp); @@ -77,25 +80,6 @@ public void RequestEnd(string protocol, bool isHttps, string scheme, string meth } } - private static void AddCustomTags(ref TagList tags, ICollection> customTags) - { - // Skip allocating enumerator if tags collection is a list. - if (customTags is List> list) - { - for (var i = 0; i < list.Count; i++) - { - tags.Add(list[i]); - } - } - else - { - foreach (var tag in customTags) - { - tags.Add(tag); - } - } - } - public void Dispose() { _meter.Dispose(); diff --git a/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs b/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs index 45eb35845854..9b11265e5db2 100644 --- a/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs +++ b/src/Hosting/Hosting/src/Internal/HttpMetricsTagsFeature.cs @@ -7,5 +7,7 @@ namespace Microsoft.AspNetCore.Hosting; internal sealed class HttpMetricsTagsFeature : IHttpMetricsTagsFeature { - public ICollection> Tags { get; } = new List>(); + public ICollection> Tags => TagsList; + + public List> TagsList { get; } = new List>(); } diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs index 2c2eed275137..b3a2dbb48eba 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs @@ -40,7 +40,7 @@ internal async Task ExecuteAsync() var connectionContext = _transportConnection; var metricsConnectionDurationEnabled = _serviceContext.Metrics.IsConnectionDurationEnabled(); var startTimestamp = 0L; - IConnectionMetricsTagsFeature? metricsTagsFeature = null; + ConnectionMetricsTagsFeature? metricsTagsFeature = null; Exception? unhandledException = null; if (metricsConnectionDurationEnabled) @@ -85,7 +85,7 @@ internal async Task ExecuteAsync() Logger.ConnectionStop(connectionContext.ConnectionId); KestrelEventSource.Log.ConnectionStop(connectionContext); - _serviceContext.Metrics.ConnectionStop(connectionContext, unhandledException, metricsTagsFeature?.Tags, startTimestamp, currentTimestamp); + _serviceContext.Metrics.ConnectionStop(connectionContext, unhandledException, metricsTagsFeature?.TagsList, startTimestamp, currentTimestamp); // Dispose the transport connection, this needs to happen before removing it from the // connection manager so that we only signal completion of this connection after the transport @@ -98,6 +98,8 @@ internal async Task ExecuteAsync() private sealed class ConnectionMetricsTagsFeature : IConnectionMetricsTagsFeature { - public ICollection> Tags { get; } = new List>(); + public ICollection> Tags => TagsList; + + public List> TagsList { get; } = new List>(); } } diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs index a3b9ef57331a..9bd1ab2a5969 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelMetrics.cs @@ -80,7 +80,7 @@ private void ConnectionStartCore(BaseConnectionContext connection) _currentConnectionsCounter.Add(1, tags); } - public void ConnectionStop(BaseConnectionContext connection, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) + public void ConnectionStop(BaseConnectionContext connection, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) { if (_currentConnectionsCounter.Enabled || _connectionDuration.Enabled) { @@ -89,7 +89,7 @@ public void ConnectionStop(BaseConnectionContext connection, Exception? exceptio } [MethodImpl(MethodImplOptions.NoInlining)] - private void ConnectionStopCore(BaseConnectionContext connection, Exception? exception, ICollection>? customTags, long startTimestamp, long currentTimestamp) + private void ConnectionStopCore(BaseConnectionContext connection, Exception? exception, List>? customTags, long startTimestamp, long currentTimestamp) { var tags = new TagList(); InitializeConnectionTags(ref tags, connection); @@ -105,32 +105,16 @@ private void ConnectionStopCore(BaseConnectionContext connection, Exception? exc // Add custom tags for duration. if (customTags != null) { - AddCustomTags(ref tags, customTags); + for (var i = 0; i < customTags.Count; i++) + { + tags.Add(customTags[i]); + } } var duration = Stopwatch.GetElapsedTime(startTimestamp, currentTimestamp); _connectionDuration.Record(duration.TotalSeconds, tags); } - private static void AddCustomTags(ref TagList tags, ICollection> customTags) - { - // Skip allocating enumerator if tags collection is a list. - if (customTags is List> list) - { - for (var i = 0; i < list.Count; i++) - { - tags.Add(list[i]); - } - } - else - { - foreach (var tag in customTags) - { - tags.Add(tag); - } - } - } - public void ConnectionRejected(BaseConnectionContext connection) { if (_rejectedConnectionsCounter.Enabled) From d0554eaa7daf4aa30705e2a270b136f82b228b38 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Thu, 13 Apr 2023 15:39:21 +0800 Subject: [PATCH 4/6] Fix tests --- .../Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs index b3a2dbb48eba..2cb095ce3258 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs @@ -46,7 +46,7 @@ internal async Task ExecuteAsync() if (metricsConnectionDurationEnabled) { metricsTagsFeature = new ConnectionMetricsTagsFeature(); - connectionContext.Features.Set(metricsTagsFeature); + connectionContext.Features.Set(metricsTagsFeature); startTimestamp = Stopwatch.GetTimestamp(); } From f17ba95c35f9056582fdd99cbc4d1c99200e8dc3 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 14 Apr 2023 14:13:22 +0800 Subject: [PATCH 5/6] Add logging to tests --- .../Hosting/test/HostingApplicationTests.cs | 21 ++++++++++++------- 1 file changed, 13 insertions(+), 8 deletions(-) diff --git a/src/Hosting/Hosting/test/HostingApplicationTests.cs b/src/Hosting/Hosting/test/HostingApplicationTests.cs index d3e9e2623b09..9c090c5d3b72 100644 --- a/src/Hosting/Hosting/test/HostingApplicationTests.cs +++ b/src/Hosting/Hosting/test/HostingApplicationTests.cs @@ -11,6 +11,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Testing; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Metrics; using Moq; @@ -18,7 +19,7 @@ namespace Microsoft.AspNetCore.Hosting.Tests; -public class HostingApplicationTests +public class HostingApplicationTests : LoggedTest { [Fact] public void Metrics() @@ -213,9 +214,11 @@ public void CreateContextCreatesNewContextIfNotUsingDefaultHttpContextFactory() hostingApplication.DisposeContext(context, null); } - [Fact] + [Theory] + [InlineData(true)] + [InlineData(false)] [QuarantinedTest("https://github.com/dotnet/aspnetcore/issues/35142")] - public void IHttpActivityFeatureIsPopulated() + public void IHttpActivityFeatureIsPopulated(bool enableLogging) { var testSource = new ActivitySource(Path.GetRandomFileName()); var dummySource = new ActivitySource(Path.GetRandomFileName()); @@ -227,7 +230,8 @@ public void IHttpActivityFeatureIsPopulated() }; ActivitySource.AddActivityListener(listener); - var hostingApplication = CreateApplication(activitySource: testSource); + var loggerFactory = enableLogging ? LoggerFactory : NullLoggerFactory.Instance; + var hostingApplication = CreateApplication(activitySource: testSource, loggerFactory: loggerFactory); var httpContext = new DefaultHttpContext(); var context = hostingApplication.CreateContext(httpContext.Features); @@ -289,7 +293,7 @@ public void IHttpActivityFeatureNotUsedFromFeatureCollection() [Fact] public void IHttpActivityFeatureIsNotPopulatedWithoutAListener() { - var hostingApplication = CreateApplication(); + var hostingApplication = CreateApplication(loggerFactory: NullLoggerFactory.Instance); var httpContext = new DefaultHttpContext(); httpContext.Features.Set(new TestHttpActivityFeature()); var context = hostingApplication.CreateContext(httpContext.Features); @@ -302,8 +306,8 @@ public void IHttpActivityFeatureIsNotPopulatedWithoutAListener() hostingApplication.DisposeContext(context, null); } - private static HostingApplication CreateApplication(IHttpContextFactory httpContextFactory = null, bool useHttpContextAccessor = false, - ActivitySource activitySource = null, IMeterFactory meterFactory = null) + private HostingApplication CreateApplication(IHttpContextFactory httpContextFactory = null, bool useHttpContextAccessor = false, + ActivitySource activitySource = null, IMeterFactory meterFactory = null, ILoggerFactory loggerFactory = null) { var services = new ServiceCollection(); services.AddOptions(); @@ -313,10 +317,11 @@ private static HostingApplication CreateApplication(IHttpContextFactory httpCont } httpContextFactory ??= new DefaultHttpContextFactory(services.BuildServiceProvider()); + loggerFactory ??= LoggerFactory; var hostingApplication = new HostingApplication( ctx => Task.CompletedTask, - NullLogger.Instance, + loggerFactory.CreateLogger("Microsoft.AspNetCore.Hosting.Diagnostics"), new DiagnosticListener("Microsoft.AspNetCore"), activitySource ?? new ActivitySource("Microsoft.AspNetCore"), DistributedContextPropagator.CreateDefaultPropagator(), From a1bf6863f546206e5d494db08e88e832368312ca Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 14 Apr 2023 14:30:16 +0800 Subject: [PATCH 6/6] Revert "Add logging to tests" This reverts commit f17ba95c35f9056582fdd99cbc4d1c99200e8dc3. --- .../Hosting/test/HostingApplicationTests.cs | 21 +++++++------------ 1 file changed, 8 insertions(+), 13 deletions(-) diff --git a/src/Hosting/Hosting/test/HostingApplicationTests.cs b/src/Hosting/Hosting/test/HostingApplicationTests.cs index 9c090c5d3b72..d3e9e2623b09 100644 --- a/src/Hosting/Hosting/test/HostingApplicationTests.cs +++ b/src/Hosting/Hosting/test/HostingApplicationTests.cs @@ -11,7 +11,6 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Testing; using Microsoft.Extensions.DependencyInjection; -using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Metrics; using Moq; @@ -19,7 +18,7 @@ namespace Microsoft.AspNetCore.Hosting.Tests; -public class HostingApplicationTests : LoggedTest +public class HostingApplicationTests { [Fact] public void Metrics() @@ -214,11 +213,9 @@ public void CreateContextCreatesNewContextIfNotUsingDefaultHttpContextFactory() hostingApplication.DisposeContext(context, null); } - [Theory] - [InlineData(true)] - [InlineData(false)] + [Fact] [QuarantinedTest("https://github.com/dotnet/aspnetcore/issues/35142")] - public void IHttpActivityFeatureIsPopulated(bool enableLogging) + public void IHttpActivityFeatureIsPopulated() { var testSource = new ActivitySource(Path.GetRandomFileName()); var dummySource = new ActivitySource(Path.GetRandomFileName()); @@ -230,8 +227,7 @@ public void IHttpActivityFeatureIsPopulated(bool enableLogging) }; ActivitySource.AddActivityListener(listener); - var loggerFactory = enableLogging ? LoggerFactory : NullLoggerFactory.Instance; - var hostingApplication = CreateApplication(activitySource: testSource, loggerFactory: loggerFactory); + var hostingApplication = CreateApplication(activitySource: testSource); var httpContext = new DefaultHttpContext(); var context = hostingApplication.CreateContext(httpContext.Features); @@ -293,7 +289,7 @@ public void IHttpActivityFeatureNotUsedFromFeatureCollection() [Fact] public void IHttpActivityFeatureIsNotPopulatedWithoutAListener() { - var hostingApplication = CreateApplication(loggerFactory: NullLoggerFactory.Instance); + var hostingApplication = CreateApplication(); var httpContext = new DefaultHttpContext(); httpContext.Features.Set(new TestHttpActivityFeature()); var context = hostingApplication.CreateContext(httpContext.Features); @@ -306,8 +302,8 @@ public void IHttpActivityFeatureIsNotPopulatedWithoutAListener() hostingApplication.DisposeContext(context, null); } - private HostingApplication CreateApplication(IHttpContextFactory httpContextFactory = null, bool useHttpContextAccessor = false, - ActivitySource activitySource = null, IMeterFactory meterFactory = null, ILoggerFactory loggerFactory = null) + private static HostingApplication CreateApplication(IHttpContextFactory httpContextFactory = null, bool useHttpContextAccessor = false, + ActivitySource activitySource = null, IMeterFactory meterFactory = null) { var services = new ServiceCollection(); services.AddOptions(); @@ -317,11 +313,10 @@ private HostingApplication CreateApplication(IHttpContextFactory httpContextFact } httpContextFactory ??= new DefaultHttpContextFactory(services.BuildServiceProvider()); - loggerFactory ??= LoggerFactory; var hostingApplication = new HostingApplication( ctx => Task.CompletedTask, - loggerFactory.CreateLogger("Microsoft.AspNetCore.Hosting.Diagnostics"), + NullLogger.Instance, new DiagnosticListener("Microsoft.AspNetCore"), activitySource ?? new ActivitySource("Microsoft.AspNetCore"), DistributedContextPropagator.CreateDefaultPropagator(),