Skip to content

Log message when connection reaches maximum concurrent streams #22452

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

Merged
merged 5 commits into from
Jun 2, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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 @@ -971,7 +971,13 @@ private void StartStream()
throw new Http2StreamErrorException(_currentHeadersStream.StreamId, CoreStrings.Http2ErrorMissingMandatoryPseudoHeaderFields, Http2ErrorCode.PROTOCOL_ERROR);
}

if (_clientActiveStreamCount > _serverSettings.MaxConcurrentStreams)
if (_clientActiveStreamCount == _serverSettings.MaxConcurrentStreams)
{
// Provide feedback in server logs that the client hit the number of maximum concurrent streams,
// and that the client is likely waiting for existing streams to be completed before it can continue.
Log.Http2MaxConcurrentStreamsReached(_context.ConnectionId);
}
else if (_clientActiveStreamCount > _serverSettings.MaxConcurrentStreams)
{
// The protocol default stream limit is infinite so the client can exceed our limit at the start of the connection.
// Refused streams can be retried, by which time the client must have received our settings frame with our limit information.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,5 +74,7 @@ internal interface IKestrelTrace : ILogger
void Http2FrameReceived(string connectionId, Http2Frame frame);

void Http2FrameSending(string connectionId, Http2Frame frame);

void Http2MaxConcurrentStreamsReached(string connectionId);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -113,6 +113,10 @@ internal class KestrelTrace : IKestrelTrace
private static readonly Action<ILogger, string, Exception> _connectionAccepted =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(39, nameof(ConnectionAccepted)), @"Connection id ""{ConnectionId}"" accepted.");

private static readonly Action<ILogger, string, Exception> _http2MaxConcurrentStreamsReached =
LoggerMessage.Define<string>(LogLevel.Debug, new EventId(40, nameof(Http2MaxConcurrentStreamsReached)),
@"Connection id ""{ConnectionId}"" reached the maximum number of concurrent HTTP/2 streams allowed.");

protected readonly ILogger _logger;

public KestrelTrace(ILogger logger)
Expand Down Expand Up @@ -286,6 +290,11 @@ public void Http2FrameSending(string connectionId, Http2Frame frame)
}
}

public void Http2MaxConcurrentStreamsReached(string connectionId)
{
_http2MaxConcurrentStreamsReached(_logger, connectionId, null);
}

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

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -55,5 +55,6 @@ 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 Http2MaxConcurrentStreamsReached(string connectionId) { }
}
}
6 changes: 6 additions & 0 deletions src/Servers/Kestrel/shared/test/CompositeKestrelTrace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -229,5 +229,11 @@ public void Http2FrameSending(string connectionId, Http2Frame frame)
_trace1.Http2FrameSending(connectionId, frame);
_trace2.Http2FrameSending(connectionId, frame);
}

public void Http2MaxConcurrentStreamsReached(string connectionId)
{
_trace1.Http2MaxConcurrentStreamsReached(connectionId);
_trace2.Http2MaxConcurrentStreamsReached(connectionId);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,28 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
{
public class Http2ConnectionTests : Http2TestBase
{
[Fact]
public async Task MaxConcurrentStreamsLogging_ReachLimit_MessageLogged()
{
await InitializeConnectionAsync(_echoApplication);

_connection.ServerSettings.MaxConcurrentStreams = 2;

await StartStreamAsync(1, _browserRequestHeaders, endStream: false);
Assert.Equal(0, TestApplicationErrorLogger.Messages.Count(m => m.EventId.Name == "Http2MaxConcurrentStreamsReached"));

// Log message because we've reached the stream limit
await StartStreamAsync(3, _browserRequestHeaders, endStream: false);
Assert.Equal(1, TestApplicationErrorLogger.Messages.Count(m => m.EventId.Name == "Http2MaxConcurrentStreamsReached"));

// This stream will error because it exceeds max concurrent streams
await StartStreamAsync(5, _browserRequestHeaders, endStream: true);
await WaitForStreamErrorAsync(5, Http2ErrorCode.REFUSED_STREAM, CoreStrings.Http2ErrorMaxStreams);
Assert.Equal(1, TestApplicationErrorLogger.Messages.Count(m => m.EventId.Name == "Http2MaxConcurrentStreamsReached"));

await StopConnectionAsync(expectedLastStreamId: 5, ignoreNonGoAwayFrames: false);
}

[Fact]
public async Task FlowControl_NoAvailability_ResponseHeadersStillFlushed()
{
Expand Down