Improve Kestrel connection metrics with error reasons (#55565)

Author: JamesNK

src/Servers/Kestrel/Core/src/Internal/BaseHttpConnectionContext.cs

@@ -20,7 +20,8 @@ public BaseHttpConnectionContext(
         IFeatureCollection connectionFeatures,
         MemoryPool<byte> memoryPool,
         IPEndPoint? localEndPoint,
-        IPEndPoint? remoteEndPoint)
+        IPEndPoint? remoteEndPoint,
+        ConnectionMetricsContext metricsContext)
     {
         ConnectionId = connectionId;
         Protocols = protocols;
@@ -31,6 +32,7 @@ public BaseHttpConnectionContext(
         MemoryPool = memoryPool;
         LocalEndPoint = localEndPoint;
         RemoteEndPoint = remoteEndPoint;
+        MetricsContext = metricsContext;
     }
 
     public string ConnectionId { get; set; }
@@ -42,6 +44,7 @@ public BaseHttpConnectionContext(
     public MemoryPool<byte> MemoryPool { get; }
     public IPEndPoint? LocalEndPoint { get; }
     public IPEndPoint? RemoteEndPoint { get; }
+    public ConnectionMetricsContext MetricsContext { get; }
 
     public ITimeoutControl TimeoutControl { get; set; } = default!; // Always set by HttpConnection
     public ExecutionContext? InitialExecutionContext { get; set; }

src/Servers/Kestrel/Core/src/Internal/Http/Http1ChunkedEncodingMessageBody.cs

@@ -5,6 +5,7 @@
 using System.Diagnostics;
 using System.IO.Pipelines;
 using Microsoft.AspNetCore.Connections;
+using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
 
 namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http;
 
@@ -136,6 +137,7 @@ private async Task PumpAsync()
                     // Read() will have already have greedily consumed the entire request body if able.
                     if (result.IsCompleted)
                     {
+                        KestrelMetrics.AddConnectionEndReason(_context.MetricsContext, ConnectionEndReason.UnexpectedEndOfRequestContent);
                         ThrowUnexpectedEndOfRequestContent();
                     }
                 }

src/Servers/Kestrel/Core/src/Internal/Http/Http1Connection.cs

@@ -62,13 +62,16 @@ public Http1Connection(HttpConnectionContext context)
             _context.ServiceContext.Log,
             _context.TimeoutControl,
             minResponseDataRateFeature: this,
+            MetricsContext,
             outputAborter: this);
 
         Input = _context.Transport.Input;
         Output = _http1Output;
         MemoryPool = _context.MemoryPool;
     }
 
+    public ConnectionMetricsContext MetricsContext => _context.MetricsContext;
+
     public PipeReader Input { get; }
 
     public bool RequestTimedOut => _requestTimedOut;
@@ -82,7 +85,7 @@ protected override void OnRequestProcessingEnded()
         if (IsUpgraded)
         {
             KestrelEventSource.Log.RequestUpgradedStop(this);
-            ServiceContext.Metrics.RequestUpgradedStop(_context.MetricsContext);
+            ServiceContext.Metrics.RequestUpgradedStop(MetricsContext);
 
             ServiceContext.ConnectionManager.UpgradedConnectionCount.ReleaseOne();
         }
@@ -98,56 +101,66 @@ protected override void OnRequestProcessingEnded()
     void IRequestProcessor.OnInputOrOutputCompleted()
     {
         // Closed gracefully.
-        _http1Output.Abort(ServerOptions.FinOnError ? new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient) : null!);
+        _http1Output.Abort(ServerOptions.FinOnError ? new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient) : null!, ConnectionEndReason.TransportCompleted);
         CancelRequestAbortedToken();
     }
 
     void IHttpOutputAborter.OnInputOrOutputCompleted()
     {
-        _http1Output.Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient));
+        _http1Output.Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient), ConnectionEndReason.TransportCompleted);
         CancelRequestAbortedToken();
     }
 
     /// <summary>
     /// Immediately kill the connection and poison the request body stream with an error.
     /// </summary>
-    public void Abort(ConnectionAbortedException abortReason)
+    public void Abort(ConnectionAbortedException abortReason, ConnectionEndReason reason)
     {
-        _http1Output.Abort(abortReason);
+        _http1Output.Abort(abortReason, reason);
         CancelRequestAbortedToken();
         PoisonBody(abortReason);
     }
 
     protected override void ApplicationAbort()
     {
         Log.ApplicationAbortedConnection(ConnectionId, TraceIdentifier);
-        Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByApplication));
+        Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByApplication), ConnectionEndReason.AbortedByApp);
     }
 
     /// <summary>
     /// Stops the request processing loop between requests.
     /// Called on all active connections when the server wants to initiate a shutdown
     /// and after a keep-alive timeout.
     /// </summary>
-    public void StopProcessingNextRequest()
+    public void StopProcessingNextRequest(ConnectionEndReason reason)
     {
-        _keepAlive = false;
+        DisableKeepAlive(reason);
         Input.CancelPendingRead();
     }
 
+    internal override void DisableKeepAlive(ConnectionEndReason reason)
+    {
+        KestrelMetrics.AddConnectionEndReason(MetricsContext, reason);
+        _keepAlive = false;
+    }
+
     public void SendTimeoutResponse()
     {
         _requestTimedOut = true;
         Input.CancelPendingRead();
     }
 
     public void HandleRequestHeadersTimeout()
-        => SendTimeoutResponse();
+    {
+        KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.RequestHeadersTimeout);
+        SendTimeoutResponse();
+    }
 
     public void HandleReadDataRateTimeout()
     {
         Debug.Assert(MinRequestBodyDataRate != null);
 
+        KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.MinRequestBodyDataRate);
         Log.RequestBodyMinimumDataRateNotSatisfied(ConnectionId, TraceIdentifier, MinRequestBodyDataRate.BytesPerSecond);
         SendTimeoutResponse();
     }
@@ -606,6 +619,7 @@ internal void EnsureHostHeaderExists()
         }
         else if (!HttpUtilities.IsHostHeaderValid(hostText))
         {
+            KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
             KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
         }
     }
@@ -616,6 +630,7 @@ private void ValidateNonOriginHostHeader(string hostText)
         {
             if (hostText != RawTarget)
             {
+                KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
                 KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
             }
         }
@@ -640,6 +655,7 @@ private void ValidateNonOriginHostHeader(string hostText)
                     }
                     else
                     {
+                        KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
                         KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
                     }
                 }
@@ -648,6 +664,7 @@ private void ValidateNonOriginHostHeader(string hostText)
 
         if (!HttpUtilities.IsHostHeaderValid(hostText))
         {
+            KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
             KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
         }
     }
@@ -707,11 +724,15 @@ protected override bool TryParseRequest(ReadResult result, out bool endConnectio
 #pragma warning disable CS0618 // Type or member is obsolete
         catch (BadHttpRequestException ex)
         {
-            DetectHttp2Preface(result.Buffer, ex);
-
+            OnBadRequest(result.Buffer, ex);
             throw;
         }
 #pragma warning restore CS0618 // Type or member is obsolete
+        catch (Exception)
+        {
+            KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.OtherError);
+            throw;
+        }
         finally
         {
             Input.AdvanceTo(reader.Position, isConsumed ? reader.Position : result.Buffer.End);
@@ -758,9 +779,65 @@ protected override bool TryParseRequest(ReadResult result, out bool endConnectio
         }
     }
 
+    internal static ConnectionEndReason GetConnectionEndReason(Microsoft.AspNetCore.Http.BadHttpRequestException ex)
+    {
+#pragma warning disable CS0618 // Type or member is obsolete
+        var kestrelEx = ex as BadHttpRequestException;
+#pragma warning restore CS0618 // Type or member is obsolete
+
+        switch (kestrelEx?.Reason)
+        {
+            case RequestRejectionReason.UnrecognizedHTTPVersion:
+                return ConnectionEndReason.InvalidHttpVersion;
+            case RequestRejectionReason.InvalidRequestLine:
+            case RequestRejectionReason.RequestLineTooLong:
+            case RequestRejectionReason.InvalidRequestTarget:
+                return ConnectionEndReason.InvalidRequestLine;
+            case RequestRejectionReason.InvalidRequestHeadersNoCRLF:
+            case RequestRejectionReason.InvalidRequestHeader:
+            case RequestRejectionReason.InvalidContentLength:
+            case RequestRejectionReason.MultipleContentLengths:
+            case RequestRejectionReason.MalformedRequestInvalidHeaders:
+            case RequestRejectionReason.InvalidCharactersInHeaderName:
+            case RequestRejectionReason.LengthRequiredHttp10:
+            case RequestRejectionReason.OptionsMethodRequired:
+            case RequestRejectionReason.ConnectMethodRequired:
+            case RequestRejectionReason.MissingHostHeader:
+            case RequestRejectionReason.MultipleHostHeaders:
+            case RequestRejectionReason.InvalidHostHeader:
+                return ConnectionEndReason.InvalidRequestHeaders;
+            case RequestRejectionReason.HeadersExceedMaxTotalSize:
+                return ConnectionEndReason.MaxRequestHeadersTotalSizeExceeded;
+            case RequestRejectionReason.TooManyHeaders:
+                return ConnectionEndReason.MaxRequestHeaderCountExceeded;
+            case RequestRejectionReason.TlsOverHttpError:
+                return ConnectionEndReason.TlsNotSupported;
+            case RequestRejectionReason.UnexpectedEndOfRequestContent:
+                return ConnectionEndReason.UnexpectedEndOfRequestContent;
+            default:
+                // In some scenarios the end reason might already be set to a more specific error
+                // and attempting to set the reason again has no impact.
+                return ConnectionEndReason.OtherError;
+        }
+    }
+
 #pragma warning disable CS0618 // Type or member is obsolete
-    private void DetectHttp2Preface(ReadOnlySequence<byte> requestData, BadHttpRequestException ex)
+    private void OnBadRequest(ReadOnlySequence<byte> requestData, BadHttpRequestException ex)
 #pragma warning restore CS0618 // Type or member is obsolete
+    {
+        // Some code shared between HTTP versions throws errors. For example, HttpRequestHeaders collection
+        // throws when an invalid content length is set.
+        // Only want to set a reasons for HTTP/1.1 connection, so set end reason by catching the exception here.
+        var reason = GetConnectionEndReason(ex);
+        KestrelMetrics.AddConnectionEndReason(MetricsContext, reason);
+
+        if (ex.Reason == RequestRejectionReason.UnrecognizedHTTPVersion)
+        {
+            DetectHttp2Preface(requestData);
+        }
+    }
+
+    private void DetectHttp2Preface(ReadOnlySequence<byte> requestData)
     {
         const int PrefaceLineLength = 16;
 
@@ -770,8 +847,7 @@ private void DetectHttp2Preface(ReadOnlySequence<byte> requestData, BadHttpReque
         {
             // If there is an unrecognized HTTP version, it is the first request on the connection, and the request line
             // bytes matches the HTTP/2 preface request line bytes then log and return a HTTP/2 GOAWAY frame.
-            if (ex.Reason == RequestRejectionReason.UnrecognizedHTTPVersion
-                && _requestCount == 1
+            if (_requestCount == 1
                 && requestData.Length >= PrefaceLineLength)
             {
                 var clientPrefaceRequestLine = Http2.Http2Connection.ClientPreface.Slice(0, PrefaceLineLength);

src/Servers/Kestrel/Core/src/Internal/Http/Http1ContentLengthMessageBody.cs

@@ -246,7 +246,7 @@ protected override void OnReadStarting()
         var maxRequestBodySize = _context.MaxRequestBodySize;
         if (_contentLength > maxRequestBodySize)
         {
-            _context.DisableHttp1KeepAlive();
+            _context.DisableKeepAlive(ConnectionEndReason.MaxRequestBodySizeExceeded);
             KestrelBadHttpRequestException.Throw(RequestRejectionReason.RequestBodyTooLarge, maxRequestBodySize.GetValueOrDefault().ToString(CultureInfo.InvariantCulture));
         }
     }

src/Servers/Kestrel/Core/src/Internal/Http/Http1MessageBody.cs

@@ -2,6 +2,7 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System.Diagnostics;
+using System.Globalization;
 using System.IO.Pipelines;
 using Microsoft.AspNetCore.Connections;
 using Microsoft.AspNetCore.Http;
@@ -68,11 +69,10 @@ protected override Task OnConsumeAsync()
         }
         catch (InvalidOperationException ex)
         {
-            var connectionAbortedException = new ConnectionAbortedException(CoreStrings.ConnectionAbortedByApplication, ex);
-            _context.ReportApplicationError(connectionAbortedException);
+            Log.RequestBodyDrainBodyReaderInvalidState(_context.ConnectionIdFeature, _context.TraceIdentifier, ex);
 
             // Have to abort the connection because we can't finish draining the request
-            _context.StopProcessingNextRequest();
+            _context.StopProcessingNextRequest(ConnectionEndReason.InvalidBodyReaderState);
             return Task.CompletedTask;
         }
 
@@ -104,18 +104,23 @@ protected async Task OnConsumeAsyncAwaited()
         }
         catch (InvalidOperationException ex)
         {
-            var connectionAbortedException = new ConnectionAbortedException(CoreStrings.ConnectionAbortedByApplication, ex);
-            _context.ReportApplicationError(connectionAbortedException);
+            Log.RequestBodyDrainBodyReaderInvalidState(_context.ConnectionIdFeature, _context.TraceIdentifier, ex);
 
             // Have to abort the connection because we can't finish draining the request
-            _context.StopProcessingNextRequest();
+            _context.StopProcessingNextRequest(ConnectionEndReason.InvalidBodyReaderState);
         }
         finally
         {
             _context.TimeoutControl.CancelTimeout();
         }
     }
 
+    protected override void OnObservedBytesExceedMaxRequestBodySize(long maxRequestBodySize)
+    {
+        _context.DisableKeepAlive(ConnectionEndReason.MaxRequestBodySizeExceeded);
+        KestrelBadHttpRequestException.Throw(RequestRejectionReason.RequestBodyTooLarge, maxRequestBodySize.ToString(CultureInfo.InvariantCulture));
+    }
+
     public static MessageBody For(
         HttpVersion httpVersion,
         HttpRequestHeaders headers,
@@ -202,6 +207,7 @@ public static MessageBody For(
         // Reject with Length Required for HTTP 1.0.
         if (httpVersion == HttpVersion.Http10 && (context.Method == HttpMethod.Post || context.Method == HttpMethod.Put))
         {
+            KestrelMetrics.AddConnectionEndReason(context.MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
             KestrelBadHttpRequestException.Throw(RequestRejectionReason.LengthRequiredHttp10, context.Method);
         }
 
@@ -221,6 +227,9 @@ protected void ThrowIfReaderCompleted()
     [StackTraceHidden]
     protected void ThrowUnexpectedEndOfRequestContent()
     {
+        // Set before calling OnInputOrOutputCompleted.
+        KestrelMetrics.AddConnectionEndReason(_context.MetricsContext, ConnectionEndReason.UnexpectedEndOfRequestContent);
+
         // OnInputOrOutputCompleted() is an idempotent method that closes the connection. Sometimes
         // input completion is observed here before the Input.OnWriterCompleted() callback is fired,
         // so we call OnInputOrOutputCompleted() now to prevent a race in our tests where a 400

src/Servers/Kestrel/Core/src/Internal/Http/Http1OutputProducer.cs

@@ -29,6 +29,7 @@ internal class Http1OutputProducer : IHttpOutputProducer, IDisposable
     private readonly MemoryPool<byte> _memoryPool;
     private readonly KestrelTrace _log;
     private readonly IHttpMinResponseDataRateFeature _minResponseDataRateFeature;
+    private readonly ConnectionMetricsContext _connectionMetricsContext;
     private readonly IHttpOutputAborter _outputAborter;
     private readonly TimingPipeFlusher _flusher;
 
@@ -75,6 +76,7 @@ public Http1OutputProducer(
         KestrelTrace log,
         ITimeoutControl timeoutControl,
         IHttpMinResponseDataRateFeature minResponseDataRateFeature,
+        ConnectionMetricsContext connectionMetricsContext,
         IHttpOutputAborter outputAborter)
     {
         // Allow appending more data to the PipeWriter when a flush is pending.
@@ -84,6 +86,7 @@ public Http1OutputProducer(
         _memoryPool = memoryPool;
         _log = log;
         _minResponseDataRateFeature = minResponseDataRateFeature;
+        _connectionMetricsContext = connectionMetricsContext;
         _outputAborter = outputAborter;
 
         _flusher = new TimingPipeFlusher(timeoutControl, log);
@@ -455,7 +458,7 @@ private void CompletePipe()
         }
     }
 
-    public void Abort(ConnectionAbortedException error)
+    public void Abort(ConnectionAbortedException error, ConnectionEndReason reason)
     {
         // Abort can be called after Dispose if there's a flush timeout.
         // It's important to still call _lifetimeFeature.Abort() in this case.
@@ -466,6 +469,8 @@ public void Abort(ConnectionAbortedException error)
                 return;
             }
 
+            KestrelMetrics.AddConnectionEndReason(_connectionMetricsContext, reason);
+
             _aborted = true;
             _connectionContext.Abort(error);