Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve Kestrel connection metrics with error reasons #55565

Open
wants to merge 41 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
41 commits
Select commit Hold shift + click to select a range
d62e9a2
Add protocol code to HTTP/2 and HTTP/3 connection metric
JamesNK Apr 25, 2024
32484b3
Add reason to connection exception
JamesNK May 7, 2024
121c074
More
JamesNK May 7, 2024
52f5fd4
Clean up
JamesNK May 7, 2024
98c752b
HTTP/1.1 and HTTP/2
JamesNK May 7, 2024
c6e4efa
Tests
JamesNK May 8, 2024
6b91a77
Fix build
JamesNK May 8, 2024
de8499b
Fix microbenchmarks
JamesNK May 8, 2024
165f8e9
Tests
JamesNK May 9, 2024
e2c9aa7
Rename
JamesNK May 9, 2024
16744ac
Fix tests
JamesNK May 9, 2024
400dde9
Clean up
JamesNK May 9, 2024
576c1d2
Remove NoError and always tag reason tag
JamesNK May 9, 2024
a4c1b32
Fix build
JamesNK May 9, 2024
6f8ecbf
Report error from failed TLS handshake
JamesNK May 10, 2024
07d7fa7
Fix build
JamesNK May 10, 2024
4bdd15d
Fix merge
JamesNK Jun 10, 2024
6ac22e1
Snake case tag value
JamesNK Jun 10, 2024
cd3aa00
Fix build
JamesNK Jun 10, 2024
beee7fa
Update
JamesNK Jun 10, 2024
88b4c8c
Update
JamesNK Jun 10, 2024
193e4a1
Tests, graceful shutdown vs abort shutdown, add reason for invalid bo…
JamesNK Jun 11, 2024
d7825d6
WIP
JamesNK Jun 15, 2024
733476a
HTTP/1.1 end reason work
JamesNK Jun 18, 2024
8e1fd7f
Comment
JamesNK Jun 18, 2024
6bb6196
Add reasons for some HTTP/1.1 request body errors
JamesNK Jun 28, 2024
8fb7354
More tests
JamesNK Jun 30, 2024
077cf06
Add exceeded max concurrent connections reason
JamesNK Jul 1, 2024
33a98af
Flaky test
JamesNK Jul 1, 2024
47f5ebe
WIP
JamesNK Jul 3, 2024
fac7e1c
WIP
JamesNK Jul 4, 2024
b90be50
Update
JamesNK Jul 4, 2024
cc3a26f
Fix build
JamesNK Jul 4, 2024
34f175b
Clean up
JamesNK Jul 4, 2024
7b517ea
PR feedback
JamesNK Jul 17, 2024
38f887c
PR feedback
JamesNK Jul 18, 2024
d066571
PR feedback
JamesNK Jul 19, 2024
550376d
Add header limits exceeded
JamesNK Jul 19, 2024
e51f962
Fix tests
JamesNK Jul 19, 2024
8238159
Fix tests
JamesNK Jul 19, 2024
43f692e
PR feedback
JamesNK Jul 20, 2024
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,8 @@ internal class BaseHttpConnectionContext
IFeatureCollection connectionFeatures,
MemoryPool<byte> memoryPool,
IPEndPoint? localEndPoint,
IPEndPoint? remoteEndPoint)
IPEndPoint? remoteEndPoint,
ConnectionMetricsContext metricsContext)
{
ConnectionId = connectionId;
Protocols = protocols;
Expand All @@ -31,6 +32,7 @@ internal class BaseHttpConnectionContext
MemoryPool = memoryPool;
LocalEndPoint = localEndPoint;
RemoteEndPoint = remoteEndPoint;
MetricsContext = metricsContext;
}

public string ConnectionId { get; set; }
Expand All @@ -42,6 +44,7 @@ internal class 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; }
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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();
}
}
Expand Down
104 changes: 90 additions & 14 deletions src/Servers/Kestrel/Core/src/Internal/Http/Http1Connection.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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();
}
Expand All @@ -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);
JamesNK marked this conversation as resolved.
Show resolved Hide resolved
CancelRequestAbortedToken();
}

void IHttpOutputAborter.OnInputOrOutputCompleted()
{
_http1Output.Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient));
_http1Output.Abort(new ConnectionAbortedException(CoreStrings.ConnectionAbortedByClient), ConnectionEndReason.TransportCompleted);
JamesNK marked this conversation as resolved.
Show resolved Hide resolved
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();
}
Expand Down Expand Up @@ -606,6 +619,7 @@ internal void EnsureHostHeaderExists()
}
else if (!HttpUtilities.IsHostHeaderValid(hostText))
{
KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
}
}
Expand All @@ -616,6 +630,7 @@ private void ValidateNonOriginHostHeader(string hostText)
{
if (hostText != RawTarget)
{
KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
}
}
Expand All @@ -640,6 +655,7 @@ private void ValidateNonOriginHostHeader(string hostText)
}
else
{
KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
}
}
Expand All @@ -648,6 +664,7 @@ private void ValidateNonOriginHostHeader(string hostText)

if (!HttpUtilities.IsHostHeaderValid(hostText))
{
KestrelMetrics.AddConnectionEndReason(MetricsContext, ConnectionEndReason.InvalidRequestHeaders);
KestrelBadHttpRequestException.Throw(RequestRejectionReason.InvalidHostHeader, hostText);
}
}
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -758,9 +779,65 @@ protected override bool TryParseRequest(ReadResult result, out bool endConnectio
}
}

internal static ConnectionEndReason GetConnectionEndReason(Microsoft.AspNetCore.Http.BadHttpRequestException ex)
amcasey marked this conversation as resolved.
Show resolved Hide resolved
{
#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;
amcasey marked this conversation as resolved.
Show resolved Hide resolved
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;

Expand All @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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));
}
}
Expand Down
21 changes: 15 additions & 6 deletions src/Servers/Kestrel/Core/src/Internal/Http/Http1MessageBody.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
halter73 marked this conversation as resolved.
Show resolved Hide resolved

// Have to abort the connection because we can't finish draining the request
_context.StopProcessingNextRequest();
_context.StopProcessingNextRequest(ConnectionEndReason.InvalidBodyReaderState);
return Task.CompletedTask;
}

Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -202,6 +207,7 @@ protected async Task OnConsumeAsyncAwaited()
// 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);
}

Expand All @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -75,6 +76,7 @@ internal class Http1OutputProducer : IHttpOutputProducer, IDisposable
KestrelTrace log,
ITimeoutControl timeoutControl,
IHttpMinResponseDataRateFeature minResponseDataRateFeature,
ConnectionMetricsContext connectionMetricsContext,
IHttpOutputAborter outputAborter)
{
// Allow appending more data to the PipeWriter when a flush is pending.
Expand All @@ -84,6 +86,7 @@ internal class Http1OutputProducer : IHttpOutputProducer, IDisposable
_memoryPool = memoryPool;
_log = log;
_minResponseDataRateFeature = minResponseDataRateFeature;
_connectionMetricsContext = connectionMetricsContext;
_outputAborter = outputAborter;

_flusher = new TimingPipeFlusher(timeoutControl, log);
Expand Down Expand Up @@ -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.
Expand All @@ -466,6 +469,8 @@ public void Abort(ConnectionAbortedException error)
return;
}

KestrelMetrics.AddConnectionEndReason(_connectionMetricsContext, reason);

_aborted = true;
_connectionContext.Abort(error);

Expand Down
Loading
Loading