Skip to content

Commit 90338b1

Browse files
Merged PR 33981: Track indicators of excessive stream resets
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. Cherry picked from !33906
2 parents ace21f3 + 95bb0b8 commit 90338b1

File tree

6 files changed

+167
-8
lines changed

6 files changed

+167
-8
lines changed

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

Lines changed: 115 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -33,14 +33,64 @@ internal partial class Http2Connection : IHttp2StreamLifetimeHandler, IHttpHeade
3333
private const PseudoHeaderFields _mandatoryRequestPseudoHeaderFields =
3434
PseudoHeaderFields.Method | PseudoHeaderFields.Path | PseudoHeaderFields.Scheme;
3535

36+
private const string MaximumEnhanceYourCalmCountProperty = "Microsoft.AspNetCore.Server.Kestrel.Http2.MaxEnhanceYourCalmCount";
37+
private const string MaximumFlowControlQueueSizeProperty = "Microsoft.AspNetCore.Server.Kestrel.Http2.MaxConnectionFlowControlQueueSize";
38+
39+
private static readonly int _enhanceYourCalmMaximumCount = GetMaximumEnhanceYourCalmCount();
40+
41+
private static int GetMaximumEnhanceYourCalmCount()
42+
{
43+
var data = AppContext.GetData(MaximumEnhanceYourCalmCountProperty);
44+
if (data is int count)
45+
{
46+
return count;
47+
}
48+
if (data is string countStr && int.TryParse(countStr, out var parsed))
49+
{
50+
return parsed;
51+
}
52+
53+
return 20; // Empirically derived
54+
}
55+
56+
// Accumulate _enhanceYourCalmCount over the course of EnhanceYourCalmTickWindowCount ticks.
57+
// This should make bursts less likely to trigger disconnects.
58+
private const int EnhanceYourCalmTickWindowCount = 5;
59+
60+
private static bool IsEnhanceYourCalmEnabled => _enhanceYourCalmMaximumCount > 0;
61+
62+
private static readonly int? ConfiguredMaximumFlowControlQueueSize = GetConfiguredMaximumFlowControlQueueSize();
63+
64+
private static int? GetConfiguredMaximumFlowControlQueueSize()
65+
{
66+
var data = AppContext.GetData(MaximumFlowControlQueueSizeProperty);
67+
68+
if (data is int count)
69+
{
70+
return count;
71+
}
72+
73+
if (data is string countStr && int.TryParse(countStr, out var parsed))
74+
{
75+
return parsed;
76+
}
77+
78+
return null;
79+
}
80+
81+
private readonly int _maximumFlowControlQueueSize;
82+
83+
private bool IsMaximumFlowControlQueueSizeEnabled => _maximumFlowControlQueueSize > 0;
84+
3685
private readonly HttpConnectionContext _context;
3786
private readonly Http2FrameWriter _frameWriter;
3887
private readonly Pipe _input;
3988
private readonly Task _inputTask;
4089
private readonly int _minAllocBufferSize;
4190
private readonly HPackDecoder _hpackDecoder;
4291
private readonly InputFlowControl _inputFlowControl;
43-
private readonly OutputFlowControl _outputFlowControl = new OutputFlowControl(new MultipleAwaitableProvider(), Http2PeerSettings.DefaultInitialWindowSize);
92+
private readonly OutputFlowControl _outputFlowControl;
93+
private readonly AwaitableProvider _outputFlowControlAwaitableProvider; // Keep our own reference so we can track queue size
4494

4595
private readonly Http2PeerSettings _serverSettings = new Http2PeerSettings();
4696
private readonly Http2PeerSettings _clientSettings = new Http2PeerSettings();
@@ -59,6 +109,9 @@ internal partial class Http2Connection : IHttp2StreamLifetimeHandler, IHttpHeade
59109
private int _clientActiveStreamCount;
60110
private int _serverActiveStreamCount;
61111

112+
private int _enhanceYourCalmCount;
113+
private int _tickCount;
114+
62115
// The following are the only fields that can be modified outside of the ProcessRequestsAsync loop.
63116
private readonly ConcurrentQueue<Http2Stream> _completedStreams = new ConcurrentQueue<Http2Stream>();
64117
private readonly StreamCloseAwaitable _streamCompletionAwaitable = new StreamCloseAwaitable();
@@ -88,6 +141,9 @@ public Http2Connection(HttpConnectionContext context)
88141
// Capture the ExecutionContext before dispatching HTTP/2 middleware. Will be restored by streams when processing request
89142
_context.InitialExecutionContext = ExecutionContext.Capture();
90143

144+
_outputFlowControlAwaitableProvider = new MultipleAwaitableProvider();
145+
_outputFlowControl = new OutputFlowControl(_outputFlowControlAwaitableProvider, Http2PeerSettings.DefaultInitialWindowSize);
146+
91147
_frameWriter = new Http2FrameWriter(
92148
context.Transport.Output,
93149
context.ConnectionContext,
@@ -129,6 +185,17 @@ public Http2Connection(HttpConnectionContext context)
129185
_serverSettings.MaxHeaderListSize = (uint)httpLimits.MaxRequestHeadersTotalSize;
130186
_serverSettings.InitialWindowSize = (uint)http2Limits.InitialStreamWindowSize;
131187

188+
_maximumFlowControlQueueSize = ConfiguredMaximumFlowControlQueueSize is null
189+
? 4 * http2Limits.MaxStreamsPerConnection // 4 is a magic number to give us some padding above the expected maximum size
190+
: (int)ConfiguredMaximumFlowControlQueueSize;
191+
192+
var minimumMaximumFlowControlQueueSize = 2 * http2Limits.MaxStreamsPerConnection; // Double to match 7.0 and 8.0
193+
if (IsMaximumFlowControlQueueSizeEnabled && _maximumFlowControlQueueSize < minimumMaximumFlowControlQueueSize)
194+
{
195+
Log.Http2FlowControlQueueMaximumTooLow(context.ConnectionId, minimumMaximumFlowControlQueueSize, _maximumFlowControlQueueSize);
196+
_maximumFlowControlQueueSize = minimumMaximumFlowControlQueueSize;
197+
}
198+
132199
// Start pool off at a smaller size if the max number of streams is less than the InitialStreamPoolSize
133200
StreamPool = new PooledStreamStack<Http2Stream>(Math.Min(InitialStreamPoolSize, http2Limits.MaxStreamsPerConnection));
134201

@@ -352,13 +419,20 @@ public async Task ProcessRequestsAsync<TContext>(IHttpApplication<TContext> appl
352419
stream.Abort(new IOException(CoreStrings.Http2StreamAborted, connectionError));
353420
}
354421

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

364438
while (StreamPool.TryPop(out var pooledStream))
@@ -1053,6 +1127,20 @@ private void StartStream()
10531127
throw new Http2StreamErrorException(_currentHeadersStream.StreamId, CoreStrings.Http2ErrorMaxStreams, Http2ErrorCode.REFUSED_STREAM);
10541128
}
10551129

1130+
if (IsMaximumFlowControlQueueSizeEnabled && _outputFlowControlAwaitableProvider.ActiveCount > _maximumFlowControlQueueSize)
1131+
{
1132+
Log.Http2FlowControlQueueOperationsExceeded(_context.ConnectionId, _maximumFlowControlQueueSize);
1133+
1134+
// Now that we've logged a useful message, we can put vague text in the exception
1135+
// messages in case they somehow make it back to the client (not expected)
1136+
1137+
// This will close the socket - we want to do that right away
1138+
Abort(new ConnectionAbortedException("HTTP/2 connection exceeded the outgoing flow control maximum queue size."));
1139+
1140+
// Throwing an exception as well will help us clean up on our end more quickly by (e.g.) skipping processing of already-buffered input
1141+
throw new Http2ConnectionErrorException(CoreStrings.Http2ConnectionFaulted, Http2ErrorCode.INTERNAL_ERROR);
1142+
}
1143+
10561144
// We don't use the _serverActiveRequestCount here as during shutdown, it and the dictionary counts get out of sync.
10571145
// The streams still exist in the dictionary until the client responds with a RST or END_STREAM.
10581146
// Also, we care about the dictionary size for too much memory consumption.
@@ -1061,6 +1149,20 @@ private void StartStream()
10611149
// Server is getting hit hard with connection resets.
10621150
// Tell client to calm down.
10631151
// TODO consider making when to send ENHANCE_YOUR_CALM configurable?
1152+
1153+
if (IsEnhanceYourCalmEnabled && Interlocked.Increment(ref _enhanceYourCalmCount) > EnhanceYourCalmTickWindowCount * _enhanceYourCalmMaximumCount)
1154+
{
1155+
Log.Http2TooManyEnhanceYourCalms(_context.ConnectionId, _enhanceYourCalmMaximumCount);
1156+
1157+
// Now that we've logged a useful message, we can put vague text in the exception
1158+
// messages in case they somehow make it back to the client (not expected)
1159+
1160+
// This will close the socket - we want to do that right away
1161+
Abort(new ConnectionAbortedException(CoreStrings.Http2ConnectionFaulted));
1162+
// Throwing an exception as well will help us clean up on our end more quickly by (e.g.) skipping processing of already-buffered input
1163+
throw new Http2ConnectionErrorException(CoreStrings.Http2ConnectionFaulted, Http2ErrorCode.ENHANCE_YOUR_CALM);
1164+
}
1165+
10641166
throw new Http2StreamErrorException(_currentHeadersStream.StreamId, CoreStrings.Http2TellClientToCalmDown, Http2ErrorCode.ENHANCE_YOUR_CALM);
10651167
}
10661168
}
@@ -1123,6 +1225,12 @@ private void AbortStream(int streamId, IOException error)
11231225
void IRequestProcessor.Tick(DateTimeOffset now)
11241226
{
11251227
Input.CancelPendingRead();
1228+
// We count EYCs over a window of a given length to avoid flagging short-lived bursts.
1229+
// At the end of each window, reset the count.
1230+
if (IsEnhanceYourCalmEnabled && ++_tickCount % EnhanceYourCalmTickWindowCount == 0)
1231+
{
1232+
Interlocked.Exchange(ref _enhanceYourCalmCount, 0);
1233+
}
11261234
}
11271235

11281236
void IHttp2StreamLifetimeHandler.OnStreamCompleted(Http2Stream stream)

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

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -78,8 +78,14 @@ internal interface IKestrelTrace : ILogger
7878

7979
void Http2FrameSending(string connectionId, Http2Frame frame);
8080

81+
void Http2TooManyEnhanceYourCalms(string connectionId, int count);
82+
8183
void Http2MaxConcurrentStreamsReached(string connectionId);
8284

85+
void Http2FlowControlQueueOperationsExceeded(string connectionId, int count);
86+
87+
void Http2FlowControlQueueMaximumTooLow(string connectionId, int expected, int actual);
88+
8389
void InvalidResponseHeaderRemoved();
8490

8591
void Http3ConnectionError(string connectionId, Http3ConnectionErrorException ex);

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

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -395,6 +395,30 @@ public void Http3GoAwayStreamId(string connectionId, long goAwayStreamId)
395395
Http3GoAwayStreamId(_http3Logger, connectionId, goAwayStreamId);
396396
}
397397

398+
[LoggerMessage(54, LogLevel.Debug, @"Connection id ""{ConnectionId}"" aborted since at least {Count} ENHANCE_YOUR_CALM responses were recorded per second.", EventName = "Http2TooManyEnhanceYourCalms")]
399+
private static partial void Http2TooManyEnhanceYourCalms(ILogger logger, string connectionId, int count);
400+
401+
public void Http2TooManyEnhanceYourCalms(string connectionId, int count)
402+
{
403+
Http2TooManyEnhanceYourCalms(_http2Logger, connectionId, count);
404+
}
405+
406+
[LoggerMessage(55, LogLevel.Debug, @"Connection id ""{ConnectionId}"" exceeded the output flow control maximum queue size of {Count}.", EventName = "Http2FlowControlQueueOperationsExceeded")]
407+
private static partial void Http2FlowControlQueueOperationsExceeded(ILogger logger, string connectionId, int count);
408+
409+
public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count)
410+
{
411+
Http2FlowControlQueueOperationsExceeded(_http3Logger, connectionId, count);
412+
}
413+
414+
[LoggerMessage(56, LogLevel.Debug, @"Connection id ""{ConnectionId}"" configured maximum flow control queue size {Actual} is less than double the maximum streams per connection {Expected}. Increasing configured value to {Expected}.", EventName = "Http2FlowControlQueueMaximumTooLow")]
415+
private static partial void Http2FlowControlQueueMaximumTooLow(ILogger logger, string connectionId, int expected, int actual);
416+
417+
public void Http2FlowControlQueueMaximumTooLow(string connectionId, int expected, int actual)
418+
{
419+
Http2FlowControlQueueMaximumTooLow(_http3Logger, connectionId, expected, actual);
420+
}
421+
398422
public virtual void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
399423
=> _generalLogger.Log(logLevel, eventId, state, exception, formatter);
400424

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

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -59,7 +59,10 @@ public void Http2ConnectionClosing(string connectionId) { }
5959
public void Http2ConnectionClosed(string connectionId, int highestOpenedStreamId) { }
6060
public void Http2FrameReceived(string connectionId, Http2Frame frame) { }
6161
public void Http2FrameSending(string connectionId, Http2Frame frame) { }
62+
public void Http2TooManyEnhanceYourCalms(string connectionId, int count) { }
6263
public void Http2MaxConcurrentStreamsReached(string connectionId) { }
64+
public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count) { }
65+
public void Http2FlowControlQueueMaximumTooLow(string connectionId, int expected, int actual) { }
6366
public void InvalidResponseHeaderRemoved() { }
6467
public void Http3ConnectionError(string connectionId, Http3ConnectionErrorException ex) { }
6568
public void Http3ConnectionClosing(string connectionId) { }

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

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
<Project Sdk="Microsoft.NET.Sdk.Web">
1+
<Project Sdk="Microsoft.NET.Sdk.Web">
22

33
<PropertyGroup>
44
<TargetFramework>$(DefaultNetCoreTargetFramework)</TargetFramework>

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

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -234,12 +234,30 @@ public void Http2FrameSending(string connectionId, Http2Frame frame)
234234
_trace2.Http2FrameSending(connectionId, frame);
235235
}
236236

237+
public void Http2TooManyEnhanceYourCalms(string connectionId, int count)
238+
{
239+
_trace1.Http2TooManyEnhanceYourCalms(connectionId, count);
240+
_trace2.Http2TooManyEnhanceYourCalms(connectionId, count);
241+
}
242+
237243
public void Http2MaxConcurrentStreamsReached(string connectionId)
238244
{
239245
_trace1.Http2MaxConcurrentStreamsReached(connectionId);
240246
_trace2.Http2MaxConcurrentStreamsReached(connectionId);
241247
}
242248

249+
public void Http2FlowControlQueueOperationsExceeded(string connectionId, int count)
250+
{
251+
_trace1.Http2FlowControlQueueOperationsExceeded(connectionId, count);
252+
_trace2.Http2FlowControlQueueOperationsExceeded(connectionId, count);
253+
}
254+
255+
public void Http2FlowControlQueueMaximumTooLow(string connectionId, int expected, int actual)
256+
{
257+
_trace1.Http2FlowControlQueueMaximumTooLow(connectionId, expected, actual);
258+
_trace2.Http2FlowControlQueueMaximumTooLow(connectionId, expected, actual);
259+
}
260+
243261
public void InvalidResponseHeaderRemoved()
244262
{
245263
_trace1.InvalidResponseHeaderRemoved();

0 commit comments

Comments
 (0)