From c74a39d0e1fd6ea8883efd2c3d3a6968b3d35fc9 Mon Sep 17 00:00:00 2001 From: Miha Zupan Date: Tue, 3 Oct 2023 04:15:17 +0200 Subject: [PATCH] React to runtime EventSource changes --- .../Http/HttpEventListenerService.cs | 125 +++++++++++++++++- src/TelemetryConsumption/Http/HttpMetrics.cs | 12 ++ .../Http/IHttpTelemetryConsumer.cs | 89 +++++++++++++ .../Sockets/SocketsEventListenerService.cs | 10 ++ .../Sockets/SocketsMetrics.cs | 7 + .../TelemetryConsumptionTests.cs | 31 ++++- 6 files changed, 265 insertions(+), 9 deletions(-) diff --git a/src/TelemetryConsumption/Http/HttpEventListenerService.cs b/src/TelemetryConsumption/Http/HttpEventListenerService.cs index d1fa16a44..6ec410bf8 100644 --- a/src/TelemetryConsumption/Http/HttpEventListenerService.cs +++ b/src/TelemetryConsumption/Http/HttpEventListenerService.cs @@ -15,7 +15,11 @@ internal sealed class HttpEventListenerService : EventListenerService "System.Net.Http"; +#if NET8_0_OR_GREATER + protected override int NumberOfMetrics => 11; +#else protected override int NumberOfMetrics => 9; +#endif public HttpEventListenerService(ILogger logger, IEnumerable telemetryConsumers, IEnumerable> metricsConsumers) : base(logger, telemetryConsumers, metricsConsumers) @@ -48,39 +52,83 @@ protected override void OnEvent(IHttpTelemetryConsumer[] consumers, EventWritten break; case 2: - Debug.Assert(eventData.EventName == "RequestStop" /* && payload.Count == 0 */); + Debug.Assert(eventData.EventName == "RequestStop" && payload.Count == (eventData.Version == 0 ? 0 : 1)); { +#if NET8_0_OR_GREATER + var statusCode = (int)payload[0]; + foreach (var consumer in consumers) + { + consumer.OnRequestStop(eventData.TimeStamp, statusCode); + } +#else foreach (var consumer in consumers) { consumer.OnRequestStop(eventData.TimeStamp); } +#endif } break; case 3: - Debug.Assert(eventData.EventName == "RequestFailed" /* && payload.Count == 0 */); + Debug.Assert(eventData.EventName == "RequestFailed" && payload.Count == (eventData.Version == 0 ? 0 : 1)); { +#if NET8_0_OR_GREATER + var exceptionMessage = (string)payload[0]; + foreach (var consumer in consumers) + { + consumer.OnRequestFailed(eventData.TimeStamp, exceptionMessage); + } +#else foreach (var consumer in consumers) { consumer.OnRequestFailed(eventData.TimeStamp); } +#endif } break; case 4: - Debug.Assert(eventData.EventName == "ConnectionEstablished" && payload.Count == 2); + Debug.Assert(eventData.EventName == "ConnectionEstablished" && payload.Count == (eventData.Version == 0 ? 2 : 7)); { var versionMajor = (int)(byte)payload[0]; var versionMinor = (int)(byte)payload[1]; +#if NET8_0_OR_GREATER + var connectionId = (long)payload[2]; + var scheme = (string)payload[3]; + var host = (string)payload[4]; + var port = (int)payload[5]; + var remoteAddress = (string?)payload[6]; + foreach (var consumer in consumers) + { + consumer.OnConnectionEstablished(eventData.TimeStamp, versionMajor, versionMinor, connectionId, scheme, host, port, remoteAddress); + } +#else foreach (var consumer in consumers) { consumer.OnConnectionEstablished(eventData.TimeStamp, versionMajor, versionMinor); } +#endif } break; case 5: - Debug.Assert(eventData.EventName == "ConnectionClosed" && payload.Count == 2); + Debug.Assert(eventData.EventName == "ConnectionClosed" && payload.Count == (eventData.Version == 0 ? 2 : 3)); + { + var versionMajor = (int)(byte)payload[0]; + var versionMinor = (int)(byte)payload[1]; +#if NET8_0_OR_GREATER + var connectionId = (long)payload[2]; + foreach (var consumer in consumers) + { + consumer.OnConnectionClosed(eventData.TimeStamp, versionMajor, versionMinor, connectionId); + } +#else + foreach (var consumer in consumers) + { + consumer.OnConnectionClosed(eventData.TimeStamp, versionMajor, versionMinor); + } +#endif + } break; case 6: @@ -97,12 +145,20 @@ protected override void OnEvent(IHttpTelemetryConsumer[] consumers, EventWritten break; case 7: - Debug.Assert(eventData.EventName == "RequestHeadersStart" && payload.Count == 0); + Debug.Assert(eventData.EventName == "RequestHeadersStart" && payload.Count == (eventData.Version == 0 ? 0 : 1)); { +#if NET8_0_OR_GREATER + var connectionId = (long)payload[0]; + foreach (var consumer in consumers) + { + consumer.OnRequestHeadersStart(eventData.TimeStamp, connectionId); + } +#else foreach (var consumer in consumers) { consumer.OnRequestHeadersStart(eventData.TimeStamp); } +#endif } break; @@ -148,14 +204,61 @@ protected override void OnEvent(IHttpTelemetryConsumer[] consumers, EventWritten break; case 12: - Debug.Assert(eventData.EventName == "ResponseHeadersStop" /* && payload.Count == 0 */); + Debug.Assert(eventData.EventName == "ResponseHeadersStop" && payload.Count == (eventData.Version == 0 ? 0 : 1)); { +#if NET8_0_OR_GREATER + var statusCode = (int)payload[0]; + foreach (var consumer in consumers) + { + consumer.OnResponseHeadersStop(eventData.TimeStamp, statusCode); + } +#else foreach (var consumer in consumers) { consumer.OnResponseHeadersStop(eventData.TimeStamp); } +#endif + } + break; + + case 13: + Debug.Assert(eventData.EventName == "ResponseContentStart" && payload.Count == 0); + { + foreach (var consumer in consumers) + { + consumer.OnResponseContentStart(eventData.TimeStamp); + } + } + break; + + case 14: + Debug.Assert(eventData.EventName == "ResponseContentStop" && payload.Count == 0); + { + foreach (var consumer in consumers) + { + consumer.OnResponseContentStop(eventData.TimeStamp); + } } break; + + case 15: + Debug.Assert(eventData.EventName == "RequestFailedDetailed" && payload.Count == 1); + // This event is more expensive to collect and requires an opt-in keyword. + Debug.Fail("We shouldn't be seeing this event as the base EventListenerService always uses EventKeywords.None."); + break; + + case 16: + Debug.Assert(eventData.EventName == "Redirect" && payload.Count == 1); +#if NET8_0_OR_GREATER + { + var redirectUri = (string)payload[0]; + foreach (var consumer in consumers) + { + consumer.OnRedirect(eventData.TimeStamp, redirectUri); + } + } +#endif + break; } } @@ -199,6 +302,16 @@ protected override bool TrySaveMetric(HttpMetrics metrics, string name, double v metrics.Http20RequestsQueueDuration = TimeSpan.FromMilliseconds(value); break; +#if NET8_0_OR_GREATER + case "http30-connections-current-total": + metrics.CurrentHttp30Connections = (long)value; + break; + + case "http30-requests-queue-duration": + metrics.Http30RequestsQueueDuration = TimeSpan.FromMilliseconds(value); + break; +#endif + default: return false; } diff --git a/src/TelemetryConsumption/Http/HttpMetrics.cs b/src/TelemetryConsumption/Http/HttpMetrics.cs index ecaab4542..6a653b547 100644 --- a/src/TelemetryConsumption/Http/HttpMetrics.cs +++ b/src/TelemetryConsumption/Http/HttpMetrics.cs @@ -61,4 +61,16 @@ public sealed class HttpMetrics /// Average time spent on queue for HTTP 2.0 requests that hit the MAX_CONCURRENT_STREAMS limit on the connection in the last metrics interval. /// public TimeSpan Http20RequestsQueueDuration { get; internal set; } + +#if NET8_0_OR_GREATER + /// + /// Number of currently open HTTP 3.0 connections. + /// + public long CurrentHttp30Connections { get; internal set; } + + /// + /// Average time spent on queue for HTTP 3.0 requests in the last metrics interval. + /// + public TimeSpan Http30RequestsQueueDuration { get; internal set; } +#endif } diff --git a/src/TelemetryConsumption/Http/IHttpTelemetryConsumer.cs b/src/TelemetryConsumption/Http/IHttpTelemetryConsumer.cs index deb925c99..78ca5c202 100644 --- a/src/TelemetryConsumption/Http/IHttpTelemetryConsumer.cs +++ b/src/TelemetryConsumption/Http/IHttpTelemetryConsumer.cs @@ -44,6 +44,14 @@ void OnRequestFailed(DateTime timestamp) { } /// Minor component of the connection's HTTP version. void OnConnectionEstablished(DateTime timestamp, int versionMajor, int versionMinor) { } + /// + /// Called when a new HTTP connection is closed. + /// + /// Timestamp when the event was fired. + /// Major component of the connection's HTTP version. + /// Minor component of the connection's HTTP version. + void OnConnectionClosed(DateTime timestamp, int versionMajor, int versionMinor) { } + /// /// Called when a request that hit the MaxConnectionsPerServer or MAX_CONCURRENT_STREAMS limit leaves the queue. /// @@ -89,4 +97,85 @@ void OnResponseHeadersStart(DateTime timestamp) { } /// /// Timestamp when the event was fired. void OnResponseHeadersStop(DateTime timestamp) { } + + /// + /// Called when starts buffering the response content. + /// This event WILL NOT be called for requests made by YARP, as they are not buffered. + /// + /// Timestamp when the event was fired. + void OnResponseContentStart(DateTime timestamp) { } + + /// + /// Called when stops buffering the response content. + /// This event WILL NOT be called for requests made by YARP, as they are not buffered. + /// + /// Timestamp when the event was fired. + void OnResponseContentStop(DateTime timestamp) { } + + // Some events were augmented in .NET 8 with more parameters. + // For backwards compatibility, they are implemented as DIMs that forward to older methods with fewer parameters. +#if NET8_0_OR_GREATER + /// + /// Called after an HTTP request. + /// + /// Timestamp when the event was fired. + /// The status code returned by the server. -1 if no response was received. + void OnRequestStop(DateTime timestamp, int statusCode) => + OnRequestStop(timestamp); + + /// + /// Called before if the request failed. + /// + /// Timestamp when the event was fired. + /// A message that describes the exception associated with this request failure. + void OnRequestFailed(DateTime timestamp, string exceptionMessage) => + OnRequestFailed(timestamp); + + /// + /// Called when a new HTTP connection is established. + /// + /// Timestamp when the event was fired. + /// Major component of the connection's HTTP version. + /// Minor component of the connection's HTTP version. + /// ID of the connection that was established, unique for this process. + /// Scheme the connection was established with. + /// Host the connection was established to. + /// Port the connection was established to. + /// The remote address this connection was established to, if available. + void OnConnectionEstablished(DateTime timestamp, int versionMajor, int versionMinor, long connectionId, string scheme, string host, int port, string? remoteAddress) => + OnConnectionEstablished(timestamp, versionMajor, versionMinor); + + /// + /// Called when a new HTTP connection is closed. + /// + /// Timestamp when the event was fired. + /// Major component of the connection's HTTP version. + /// Minor component of the connection's HTTP version. + /// ID of the connection that was closed. + void OnConnectionClosed(DateTime timestamp, int versionMajor, int versionMinor, long connectionId) => + OnConnectionClosed(timestamp, versionMajor, versionMinor); + + /// + /// Called before sending the request headers. + /// + /// Timestamp when the event was fired. + /// ID of the connection we are sending this request on. + void OnRequestHeadersStart(DateTime timestamp, long connectionId) => + OnRequestHeadersStart(timestamp); + + /// + /// Called after reading all response headers. + /// + /// Timestamp when the event was fired. + /// The status code returned by the server. + void OnResponseHeadersStop(DateTime timestamp, int statusCode) => + OnResponseHeadersStop(timestamp); + + /// + /// Called before a request is redirected if is enabled. + /// + /// Timestamp when the event was fired. + /// The uri the request is being redirected to. + void OnRedirect(DateTime timestamp, string redirectUri) { } +#endif } diff --git a/src/TelemetryConsumption/Sockets/SocketsEventListenerService.cs b/src/TelemetryConsumption/Sockets/SocketsEventListenerService.cs index 7441ef3f5..47b700181 100644 --- a/src/TelemetryConsumption/Sockets/SocketsEventListenerService.cs +++ b/src/TelemetryConsumption/Sockets/SocketsEventListenerService.cs @@ -14,7 +14,11 @@ internal sealed class SocketsEventListenerService : EventListenerService "System.Net.Sockets"; +#if NET8_0_OR_GREATER + protected override int NumberOfMetrics => 7; +#else protected override int NumberOfMetrics => 6; +#endif public SocketsEventListenerService(ILogger logger, IEnumerable telemetryConsumers, IEnumerable> metricsConsumers) : base(logger, telemetryConsumers, metricsConsumers) @@ -94,6 +98,12 @@ protected override bool TrySaveMetric(SocketsMetrics metrics, string name, doubl metrics.DatagramsSent = longValue; break; +#if NET8_0_OR_GREATER + case "current-outgoing-connect-attempts": + metrics.CurrentOutgoingConnectAttempts = longValue; + break; +#endif + default: return false; } diff --git a/src/TelemetryConsumption/Sockets/SocketsMetrics.cs b/src/TelemetryConsumption/Sockets/SocketsMetrics.cs index 28c17e917..b9d004aa8 100644 --- a/src/TelemetryConsumption/Sockets/SocketsMetrics.cs +++ b/src/TelemetryConsumption/Sockets/SocketsMetrics.cs @@ -46,4 +46,11 @@ public sealed class SocketsMetrics /// Number of datagrams sent since telemetry was enabled. /// public long DatagramsSent { get; internal set; } + +#if NET8_0_OR_GREATER + /// + /// Number of outgoing (Connect) Socket connection attempts that are currently in progress. + /// + public long CurrentOutgoingConnectAttempts { get; internal set; } +#endif } diff --git a/test/ReverseProxy.FunctionalTests/TelemetryConsumptionTests.cs b/test/ReverseProxy.FunctionalTests/TelemetryConsumptionTests.cs index 4ff64703b..b89b17c93 100644 --- a/test/ReverseProxy.FunctionalTests/TelemetryConsumptionTests.cs +++ b/test/ReverseProxy.FunctionalTests/TelemetryConsumptionTests.cs @@ -143,7 +143,7 @@ await test.Invoke(async uri => "OnForwarderStage-ResponseContentTransferStart", "OnContentTransferred", "OnForwarderStop", - "OnRequestStop-Kestrel" + "OnRequestStop-Kestrel", }; if (!useHttpsOnDestination) @@ -164,8 +164,21 @@ await test.Invoke(async uri => [InlineData(RegistrationApproach.Manual)] public async Task NonProxyTelemetryConsumptionWorks(RegistrationApproach registrationApproach) { + var redirected = false; + var test = new TestEnvironment( - async context => await context.Response.WriteAsync("Foo")) + async context => + { + if (redirected) + { + await context.Response.WriteAsync("Foo"); + } + else + { + context.Response.Redirect("/foo"); + redirected = true; + } + }) { UseHttpsOnDestination = true, ConfigureProxy = proxyBuilder => RegisterTelemetryConsumers(proxyBuilder.Services, registrationApproach), @@ -189,7 +202,16 @@ await test.Invoke(async uri => "OnRequestHeadersStop", "OnResponseHeadersStart", "OnResponseHeadersStop", - "OnRequestStop" +#if NET8_0_OR_GREATER + "OnRedirect", +#endif + "OnRequestHeadersStart", + "OnRequestHeadersStop", + "OnResponseHeadersStart", + "OnResponseHeadersStop", + "OnResponseContentStart", + "OnResponseContentStop", + "OnRequestStop", }; foreach (var consumerType in new[] { typeof(TelemetryConsumer), typeof(SecondTelemetryConsumer) }) @@ -250,6 +272,8 @@ public void OnRequestStart(DateTime timestamp, string scheme, string host, int p public void OnRequestContentStop(DateTime timestamp, long contentLength) => AddStage(nameof(OnRequestContentStop), timestamp); public void OnResponseHeadersStart(DateTime timestamp) => AddStage(nameof(OnResponseHeadersStart), timestamp); public void OnResponseHeadersStop(DateTime timestamp) => AddStage(nameof(OnResponseHeadersStop), timestamp); + public void OnResponseContentStart(DateTime timestamp) => AddStage(nameof(OnResponseContentStart), timestamp); + public void OnResponseContentStop(DateTime timestamp) => AddStage(nameof(OnResponseContentStop), timestamp); public void OnResolutionStart(DateTime timestamp, string hostNameOrAddress) => AddStage(nameof(OnResolutionStart), timestamp); public void OnResolutionStop(DateTime timestamp) => AddStage(nameof(OnResolutionStop), timestamp); public void OnResolutionFailed(DateTime timestamp) => AddStage(nameof(OnResolutionFailed), timestamp); @@ -261,6 +285,7 @@ public void OnRequestStart(DateTime timestamp, string scheme, string host, int p public void OnConnectFailed(DateTime timestamp, SocketError error, string exceptionMessage) => AddStage(nameof(OnConnectFailed), timestamp); public void OnRequestStart(DateTime timestamp, string connectionId, string requestId, string httpVersion, string path, string method) => AddStage($"{nameof(OnRequestStart)}-Kestrel", timestamp); public void OnRequestStop(DateTime timestamp, string connectionId, string requestId, string httpVersion, string path, string method) => AddStage($"{nameof(OnRequestStop)}-Kestrel", timestamp); + public void OnRedirect(DateTime timestamp, string redirectUri) => AddStage(nameof(OnRedirect), timestamp); } [Theory]