Skip to content

Commit

Permalink
Track indicators of excessive stream resets
Browse files Browse the repository at this point in the history
If the server has to send a lot of ENHANCE_YOUR_CALM messages or the output control flow queue is very large, there are probably a larger than expected number of client-initiated stream resets.
  • Loading branch information
amcasey authored and wtgodbe committed Oct 18, 2023
1 parent 46c1fe6 commit 966785f
Show file tree
Hide file tree
Showing 6 changed files with 134 additions and 8 deletions.
106 changes: 99 additions & 7 deletions src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs
Original file line number Diff line number Diff line change
Expand Up @@ -33,14 +33,51 @@ internal partial class Http2Connection : IHttp2StreamLifetimeHandler, IHttpHeade
private const PseudoHeaderFields _mandatoryRequestPseudoHeaderFields =
PseudoHeaderFields.Method | PseudoHeaderFields.Path | PseudoHeaderFields.Scheme;

private const string EnhanceYourCalmMaximumCountProperty = "Microsoft.AspNetCore.Server.Kestrel.Http2.EnhanceYourCalmCount";
private const string MaximumFlowControlQueueSizeProperty = "Microsoft.AspNetCore.Server.Kestrel.Http2.MaxConnectionFlowControlQueueSize";

private static readonly int _enhanceYourCalmMaximumCount = AppContext.GetData(EnhanceYourCalmMaximumCountProperty) is int eycMaxCount
? eycMaxCount
: 10;

// Accumulate _enhanceYourCalmCount over the course of EnhanceYourCalmTickWindowCount ticks.
// This should make bursts less likely to trigger disconnects.
private const int EnhanceYourCalmTickWindowCount = 5;

private static bool IsEnhanceYourCalmEnabled => _enhanceYourCalmMaximumCount > 0;

private static readonly int? ConfiguredMaximumFlowControlQueueSize = GetConfiguredMaximumFlowControlQueueSize();

private static int? GetConfiguredMaximumFlowControlQueueSize()
{
var data = AppContext.GetData(MaximumFlowControlQueueSizeProperty);

if (data is int count)
{
return count;
}

if (data is string countStr && int.TryParse(countStr, out var parsed))
{
return parsed;
}

return null;
}

private readonly int _maximumFlowControlQueueSize;

private bool IsMaximumFlowControlQueueSizeEnabled => _maximumFlowControlQueueSize > 0;

private readonly HttpConnectionContext _context;
private readonly Http2FrameWriter _frameWriter;
private readonly Pipe _input;
private readonly Task _inputTask;
private readonly int _minAllocBufferSize;
private readonly HPackDecoder _hpackDecoder;
private readonly InputFlowControl _inputFlowControl;
private readonly OutputFlowControl _outputFlowControl = new OutputFlowControl(new MultipleAwaitableProvider(), Http2PeerSettings.DefaultInitialWindowSize);
private readonly OutputFlowControl _outputFlowControl;
private readonly AwaitableProvider _outputFlowControlAwaitableProvider; // Keep our own reference so we can track queue size

private readonly Http2PeerSettings _serverSettings = new Http2PeerSettings();
private readonly Http2PeerSettings _clientSettings = new Http2PeerSettings();
Expand All @@ -59,6 +96,9 @@ internal partial class Http2Connection : IHttp2StreamLifetimeHandler, IHttpHeade
private int _clientActiveStreamCount;
private int _serverActiveStreamCount;

private int _enhanceYourCalmCount;
private int _tickCount;

// The following are the only fields that can be modified outside of the ProcessRequestsAsync loop.
private readonly ConcurrentQueue<Http2Stream> _completedStreams = new ConcurrentQueue<Http2Stream>();
private readonly StreamCloseAwaitable _streamCompletionAwaitable = new StreamCloseAwaitable();
Expand Down Expand Up @@ -88,6 +128,9 @@ public Http2Connection(HttpConnectionContext context)
// Capture the ExecutionContext before dispatching HTTP/2 middleware. Will be restored by streams when processing request
_context.InitialExecutionContext = ExecutionContext.Capture();

_outputFlowControlAwaitableProvider = new MultipleAwaitableProvider();
_outputFlowControl = new OutputFlowControl(_outputFlowControlAwaitableProvider, Http2PeerSettings.DefaultInitialWindowSize);

_frameWriter = new Http2FrameWriter(
context.Transport.Output,
context.ConnectionContext,
Expand Down Expand Up @@ -129,6 +172,16 @@ public Http2Connection(HttpConnectionContext context)
_serverSettings.MaxHeaderListSize = (uint)httpLimits.MaxRequestHeadersTotalSize;
_serverSettings.InitialWindowSize = (uint)http2Limits.InitialStreamWindowSize;

_maximumFlowControlQueueSize = ConfiguredMaximumFlowControlQueueSize is null
? 4 * http2Limits.MaxStreamsPerConnection
: (int)ConfiguredMaximumFlowControlQueueSize;

if (_maximumFlowControlQueueSize < http2Limits.MaxStreamsPerConnection)
{
_maximumFlowControlQueueSize = http2Limits.MaxStreamsPerConnection;
Log.LogTrace($"The configured maximum flow control queue size {ConfiguredMaximumFlowControlQueueSize} is less than the maximum streams per connection {http2Limits.MaxStreamsPerConnection} - increasing to match.");
}

// Start pool off at a smaller size if the max number of streams is less than the InitialStreamPoolSize
StreamPool = new PooledStreamStack<Http2Stream>(Math.Min(InitialStreamPoolSize, http2Limits.MaxStreamsPerConnection));

Expand Down Expand Up @@ -352,13 +405,20 @@ public async Task ProcessRequestsAsync<TContext>(IHttpApplication<TContext> appl
stream.Abort(new IOException(CoreStrings.Http2StreamAborted, connectionError));
}

// Use the server _serverActiveStreamCount to drain all requests on the server side.
// Can't use _clientActiveStreamCount now as we now decrement that count earlier/
// Can't use _streams.Count as we wait for RST/END_STREAM before removing the stream from the dictionary
while (_serverActiveStreamCount > 0)
// For some reason, this loop doesn't terminate when we're trying to abort.
// Since we're making a narrow fix for a patch, we'll bypass it in such scenarios.
// TODO: This is probably a bug - something in here should probably detect aborted
// connections and short-circuit.
if (!(IsEnhanceYourCalmEnabled || IsMaximumFlowControlQueueSizeEnabled) || error is not Http2ConnectionErrorException)
{
await _streamCompletionAwaitable;
UpdateCompletedStreams();
// Use the server _serverActiveStreamCount to drain all requests on the server side.
// Can't use _clientActiveStreamCount now as we now decrement that count earlier/
// Can't use _streams.Count as we wait for RST/END_STREAM before removing the stream from the dictionary
while (_serverActiveStreamCount > 0)
{
await _streamCompletionAwaitable;
UpdateCompletedStreams();
}
}

while (StreamPool.TryPop(out var pooledStream))
Expand Down Expand Up @@ -1053,6 +1113,20 @@ private void StartStream()
throw new Http2StreamErrorException(_currentHeadersStream.StreamId, CoreStrings.Http2ErrorMaxStreams, Http2ErrorCode.REFUSED_STREAM);
}

if (IsMaximumFlowControlQueueSizeEnabled && _outputFlowControlAwaitableProvider.ActiveCount > _maximumFlowControlQueueSize)
{
Log.Http2FlowControlQueueOperationsExceeded(_context.ConnectionId, _maximumFlowControlQueueSize);

// Now that we've logged a useful message, we can put vague text in the exception
// messages in case they somehow make it back to the client (not expected)

// This will close the socket - we want to do that right away
Abort(new ConnectionAbortedException("HTTP/2 connection exceeded the outgoing flow control maximum queue size."));

// Throwing an exception as well will help us clean up on our end more quickly by (e.g.) skipping processing of already-buffered input
throw new Http2ConnectionErrorException(CoreStrings.Http2ConnectionFaulted, Http2ErrorCode.INTERNAL_ERROR);
}

// We don't use the _serverActiveRequestCount here as during shutdown, it and the dictionary counts get out of sync.
// The streams still exist in the dictionary until the client responds with a RST or END_STREAM.
// Also, we care about the dictionary size for too much memory consumption.
Expand All @@ -1061,6 +1135,20 @@ private void StartStream()
// Server is getting hit hard with connection resets.
// Tell client to calm down.
// TODO consider making when to send ENHANCE_YOUR_CALM configurable?

if (IsEnhanceYourCalmEnabled && Interlocked.Increment(ref _enhanceYourCalmCount) > EnhanceYourCalmTickWindowCount * _enhanceYourCalmMaximumCount)
{
Log.Http2TooManyEnhanceYourCalms(_context.ConnectionId, _enhanceYourCalmMaximumCount);

// Now that we've logged a useful message, we can put vague text in the exception
// messages in case they somehow make it back to the client (not expected)

// This will close the socket - we want to do that right away
Abort(new ConnectionAbortedException(CoreStrings.Http2ConnectionFaulted));
// Throwing an exception as well will help us clean up on our end more quickly by (e.g.) skipping processing of already-buffered input
throw new Http2ConnectionErrorException(CoreStrings.Http2ConnectionFaulted, Http2ErrorCode.ENHANCE_YOUR_CALM);
}

throw new Http2StreamErrorException(_currentHeadersStream.StreamId, CoreStrings.Http2TellClientToCalmDown, Http2ErrorCode.ENHANCE_YOUR_CALM);
}
}
Expand Down Expand Up @@ -1123,6 +1211,10 @@ private void AbortStream(int streamId, IOException error)
void IRequestProcessor.Tick(DateTimeOffset now)
{
Input.CancelPendingRead();
if (IsEnhanceYourCalmEnabled && ++_tickCount % EnhanceYourCalmTickWindowCount == 0)
{
Interlocked.Exchange(ref _enhanceYourCalmCount, 0);
}
}

void IHttp2StreamLifetimeHandler.OnStreamCompleted(Http2Stream stream)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -78,8 +78,12 @@ internal interface IKestrelTrace : ILogger

void Http2FrameSending(string connectionId, Http2Frame frame);

void Http2TooManyEnhanceYourCalms(string connectionId, int count);

void Http2MaxConcurrentStreamsReached(string connectionId);

void Http2FlowControlQueueOperationsExceeded(string connectionId, int count);

void InvalidResponseHeaderRemoved();

void Http3ConnectionError(string connectionId, Http3ConnectionErrorException ex);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -395,6 +395,22 @@ public void Http3GoAwayStreamId(string connectionId, long goAwayStreamId)
Http3GoAwayStreamId(_http3Logger, connectionId, goAwayStreamId);
}

[LoggerMessage(54, LogLevel.Error, @"Connection id ""{ConnectionId}"" aborted since at least ""{Count}"" ENHANCE_YOUR_CALM responses were required per second.", EventName = "Http2TooManyEnhanceYourCalms")]
private static partial void Http2TooManyEnhanceYourCalms(ILogger logger, string connectionId, int count);

public void Http2TooManyEnhanceYourCalms(string connectionId, int count)
{
Http2TooManyEnhanceYourCalms(_http2Logger, connectionId, count);
}

[LoggerMessage(55, LogLevel.Error, @"Connection id ""{ConnectionId}"" exceeded the output flow control maximum queue size of ""{Count}"".", EventName = "Http2FlowControlQueueOperationsExceeded")]
private static partial void Http2FlowControlQueueOperationsExceeded(ILogger logger, string connectionId, int count);

public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count)
{
Http2FlowControlQueueOperationsExceeded(_http3Logger, connectionId, count);
}

public virtual void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
=> _generalLogger.Log(logLevel, eventId, state, exception, formatter);

Expand Down
2 changes: 2 additions & 0 deletions src/Servers/Kestrel/perf/Microbenchmarks/Mocks/MockTrace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,9 @@ public void Http2ConnectionClosing(string connectionId) { }
public void Http2ConnectionClosed(string connectionId, int highestOpenedStreamId) { }
public void Http2FrameReceived(string connectionId, Http2Frame frame) { }
public void Http2FrameSending(string connectionId, Http2Frame frame) { }
public void Http2TooManyEnhanceYourCalms(string connectionId, int count) { }
public void Http2MaxConcurrentStreamsReached(string connectionId) { }
public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count) { }
public void InvalidResponseHeaderRemoved() { }
public void Http3ConnectionError(string connectionId, Http3ConnectionErrorException ex) { }
public void Http3ConnectionClosing(string connectionId) { }
Expand Down
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
<Project Sdk="Microsoft.NET.Sdk.Web">
<Project Sdk="Microsoft.NET.Sdk.Web">

<PropertyGroup>
<TargetFramework>$(DefaultNetCoreTargetFramework)</TargetFramework>
Expand Down
12 changes: 12 additions & 0 deletions src/Servers/Kestrel/shared/test/CompositeKestrelTrace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -234,12 +234,24 @@ public void Http2FrameSending(string connectionId, Http2Frame frame)
_trace2.Http2FrameSending(connectionId, frame);
}

public void Http2TooManyEnhanceYourCalms(string connectionId, int count)
{
_trace1.Http2TooManyEnhanceYourCalms(connectionId, count);
_trace2.Http2TooManyEnhanceYourCalms(connectionId, count);
}

public void Http2MaxConcurrentStreamsReached(string connectionId)
{
_trace1.Http2MaxConcurrentStreamsReached(connectionId);
_trace2.Http2MaxConcurrentStreamsReached(connectionId);
}

public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count)
{
_trace1.Http2FlowControlQueueOperationsExceeded(connectionId, count);
_trace2.Http2FlowControlQueueOperationsExceeded(connectionId, count);
}

public void InvalidResponseHeaderRemoved()
{
_trace1.InvalidResponseHeaderRemoved();
Expand Down

0 comments on commit 966785f

Please sign in to comment.