Track indicators of excessive stream resets

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.

Author: amcasey

src/Servers/Kestrel/Core/src/Internal/Http2/Http2Connection.cs

@@ -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();
@@ -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();
@@ -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,
@@ -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));
 
@@ -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))
@@ -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.
@@ -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);
  }
  }
@@ -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)

src/Servers/Kestrel/Core/src/Internal/Infrastructure/IKestrelTrace.cs

@@ -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);

src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelTrace.cs

@@ -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);
 

src/Servers/Kestrel/perf/Microbenchmarks/Mocks/MockTrace.cs

@@ -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) { }

src/Servers/Kestrel/samples/Http2SampleApp/Http2SampleApp.csproj

@@ -1,4 +1,4 @@
-<Project Sdk="Microsoft.NET.Sdk.Web">
+<Project Sdk="Microsoft.NET.Sdk.Web">
 
  <PropertyGroup>
  <TargetFramework>$(DefaultNetCoreTargetFramework)</TargetFramework>

src/Servers/Kestrel/shared/test/CompositeKestrelTrace.cs

@@ -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();