Skip to content
This repository was archived by the owner on Dec 18, 2018. It is now read-only.

Always start the response before draining the request. #2109

Merged
Tratcher merged 1 commit into from
Jan 10, 2018
Merged

Always start the response before draining the request. #2109

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
31 changes: 13 additions & 18 deletions src/Kestrel.Core/Internal/Http/HttpProtocol.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -517,31 +517,26 @@ public async Task ProcessRequestsAsync<TContext>(IHttpApplication<TContext> appl
// If _requestAbort is set, the connection has already been closed.
if (_requestAborted == 0)
{
if (HasResponseStarted)
{
// If the response has already started, call ProduceEnd() before
// consuming the rest of the request body to prevent
// delaying clients waiting for the chunk terminator:
//
// https://github.com/dotnet/corefx/issues/17330#issuecomment-288248663
//
// ProduceEnd() must be called before _application.DisposeContext(), to ensure
// HttpContext.Response.StatusCode is correctly set when
// IHttpContextFactory.Dispose(HttpContext) is called.
await ProduceEnd();
}
// Call ProduceEnd() before consuming the rest of the request body to prevent
// delaying clients waiting for the chunk terminator:
//
// https://github.com/dotnet/corefx/issues/17330#issuecomment-288248663
//
// This also prevents the 100 Continue response from being sent if the app
// never tried to read the body.
// https://github.com/aspnet/KestrelHttpServer/issues/2102
//
// ProduceEnd() must be called before _application.DisposeContext(), to ensure
// HttpContext.Response.StatusCode is correctly set when
// IHttpContextFactory.Dispose(HttpContext) is called.
await ProduceEnd();

// ForZeroContentLength does not complete the reader nor the writer
if (!messageBody.IsEmpty && _keepAlive)
{
// Finish reading the request body in case the app did not.
await messageBody.ConsumeAsync();
}

if (!HasResponseStarted)
{
await ProduceEnd();
}
}
else if (!HasResponseStarted)
{
Expand Down
3 changes: 2 additions & 1 deletion test/Kestrel.FunctionalTests/MaxRequestBodySizeTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.

using System;
using System.IO;
using System.Text;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http.Features;
Expand Down Expand Up @@ -140,7 +141,7 @@ await connection.Receive(
[Fact]
public async Task DoesNotRejectBodylessGetRequestWithZeroMaxRequestBodySize()
{
using (var server = new TestServer(context => Task.CompletedTask,
using (var server = new TestServer(context => context.Request.Body.CopyToAsync(Stream.Null),
new TestServiceContext { ServerOptions = { Limits = { MaxRequestBodySize = 0 } } }))
{
using (var connection = server.CreateConnection())
Expand Down
16 changes: 13 additions & 3 deletions test/Kestrel.FunctionalTests/RequestBodyTimeoutTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,12 @@
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Server.Kestrel.Core;
using Microsoft.AspNetCore.Server.Kestrel.Core.Features;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
using Microsoft.AspNetCore.Testing;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Testing;
using Xunit;

namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
Expand Down Expand Up @@ -66,12 +69,16 @@ await connection.ReceiveForcedEnd(
[Fact]
public async Task RequestTimesOutWhenNotDrainedWithinDrainTimeoutPeriod()
{
var sink = new TestSink();
var logger = new TestLogger("TestLogger", sink, enabled: true);

// This test requires a real clock since we can't control when the drain timeout is set
var systemClock = new SystemClock();
var serviceContext = new TestServiceContext
{
SystemClock = systemClock,
DateHeaderValueManager = new DateHeaderValueManager(systemClock)
DateHeaderValueManager = new DateHeaderValueManager(systemClock),
Log = new KestrelTrace(logger)
};

var appRunningEvent = new ManualResetEventSlim();
Expand All @@ -96,17 +103,20 @@ await connection.Send(
Assert.True(appRunningEvent.Wait(TimeSpan.FromSeconds(10)));

await connection.Receive(
"HTTP/1.1 408 Request Timeout",
"Connection: close",
"HTTP/1.1 200 OK",
"");
await connection.ReceiveStartsWith(
"Date: ");
// Disconnected due to the timeout
await connection.ReceiveForcedEnd(
"Content-Length: 0",
"",
"");
}
}

Assert.Contains(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status408RequestTimeout);
}

[Fact]
Expand Down
108 changes: 76 additions & 32 deletions test/Kestrel.FunctionalTests/ResponseTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -257,8 +257,8 @@ public Task ResponseStatusCodeSetBeforeHttpContextDisposedRequestMalformed()
{
return Task.CompletedTask;
},
expectedClientStatusCode: null,
expectedServerStatusCode: HttpStatusCode.BadRequest,
expectedClientStatusCode: HttpStatusCode.OK,
expectedServerStatusCode: HttpStatusCode.OK,
sendMalformedRequest: true);
}

Expand Down Expand Up @@ -289,8 +289,8 @@ public Task ResponseStatusCodeSetBeforeHttpContextDisposedRequestMalformedReadIg
{
}
},
expectedClientStatusCode: null,
expectedServerStatusCode: HttpStatusCode.BadRequest,
expectedClientStatusCode: HttpStatusCode.OK,
expectedServerStatusCode: HttpStatusCode.OK,
sendMalformedRequest: true);
}

Expand All @@ -311,8 +311,12 @@ private static async Task ResponseStatusCodeSetBeforeHttpContextDispose(
disposedTcs.TrySetResult(c.Response.StatusCode);
});

using (var server = new TestServer(handler, new TestServiceContext(), new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)),
services => services.AddSingleton(mockHttpContextFactory.Object)))
var sink = new TestSink();
var logger = new TestLogger("TestLogger", sink, enabled: true);

using (var server = new TestServer(handler, new TestServiceContext() { Log = new KestrelTrace(logger) },
new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)),
services => services.AddSingleton(mockHttpContextFactory.Object)))
{
if (!sendMalformedRequest)
{
Expand Down Expand Up @@ -342,32 +346,57 @@ await connection.Send(
"Transfer-Encoding: chunked",
"",
"gg");
await connection.ReceiveForcedEnd(
"HTTP/1.1 400 Bad Request",
"Connection: close",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
if (expectedClientStatusCode == HttpStatusCode.OK)

@halter73 halter73 Jan 9, 2018

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do expectedClientStatusCode and expectedServerStatusCode always match now?

@Tratcher Tratcher Jan 9, 2018

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No. Some tests set null vs 0, and one sets null vs 400.

{
await connection.ReceiveForcedEnd(
"HTTP/1.1 200 OK",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
}
else
{
await connection.ReceiveForcedEnd(
"HTTP/1.1 400 Bad Request",
"Connection: close",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
}
}
}

var disposedStatusCode = await disposedTcs.Task.TimeoutAfter(TimeSpan.FromSeconds(10));
Assert.Equal(expectedServerStatusCode, (HttpStatusCode)disposedStatusCode);
}

if (sendMalformedRequest)
{
Assert.Contains(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status400BadRequest);
}
else
{
Assert.DoesNotContain(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status400BadRequest);
}
}

// https://github.com/aspnet/KestrelHttpServer/pull/1111/files#r80584475 explains the reason for this test.
[Fact]
public async Task SingleErrorResponseSentWhenAppSwallowsBadRequestException()
public async Task NoErrorResponseSentWhenAppSwallowsBadRequestException()
{
BadHttpRequestException readException = null;
var sink = new TestSink();
var logger = new TestLogger("TestLogger", sink, enabled: true);

using (var server = new TestServer(async httpContext =>
{
readException = await Assert.ThrowsAsync<BadHttpRequestException>(
async () => await httpContext.Request.Body.ReadAsync(new byte[1], 0, 1));
}))
}, new TestServiceContext() { Log = new KestrelTrace(logger) }))
{
using (var connection = server.CreateConnection())
{
Expand All @@ -378,8 +407,7 @@ await connection.Send(
"",
"gg");
await connection.ReceiveForcedEnd(
"HTTP/1.1 400 Bad Request",
"Connection: close",
"HTTP/1.1 200 OK",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
Expand All @@ -388,6 +416,9 @@ await connection.ReceiveForcedEnd(
}

Assert.NotNull(readException);

Assert.Contains(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status400BadRequest);
}

[Fact]
Expand Down Expand Up @@ -1474,9 +1505,13 @@ await connection.Receive(
}

[Fact]
public async Task WhenResponseNotStartedResponseEndedAfterConsumingRequestBody()
public async Task WhenResponseNotStartedResponseEndedBeforeConsumingRequestBody()
{
using (var server = new TestServer(httpContext => Task.CompletedTask))
var sink = new TestSink();
var logger = new TestLogger("TestLogger", sink, enabled: true);

using (var server = new TestServer(httpContext => Task.CompletedTask,
new TestServiceContext() { Log = new KestrelTrace(logger) }))
{
using (var connection = server.CreateConnection())
{
Expand All @@ -1487,27 +1522,32 @@ await connection.Send(
"",
"gg");

// If the expected behavior is regressed, this will receive
// a success response because the server flushed the response
// before reading the malformed chunk header in the request.
// This will receive a success response because the server flushed the response
// before reading the malformed chunk header in the request, but then it will close
// the connection.
await connection.ReceiveForcedEnd(
"HTTP/1.1 400 Bad Request",
"Connection: close",
"HTTP/1.1 200 OK",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
}
}

Assert.Contains(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status400BadRequest);
}

[Fact]
public async Task Sending100ContinueDoesNotStartResponse()
{
var sink = new TestSink();
var logger = new TestLogger("TestLogger", sink, enabled: true);

using (var server = new TestServer(httpContext =>
{
return httpContext.Request.Body.ReadAsync(new byte[1], 0, 1);
}))
}, new TestServiceContext() { Log = new KestrelTrace(logger) }))
{
using (var connection = server.CreateConnection())
{
Expand All @@ -1530,6 +1570,13 @@ await connection.Send(
"a",
"");

await connection.Receive(
"HTTP/1.1 200 OK",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");

// This will be consumed by Http1Connection when it attempts to
// consume the request body and will cause an error.
await connection.Send(
Expand All @@ -1538,15 +1585,12 @@ await connection.Send(
// If 100 Continue sets HttpProtocol.HasResponseStarted to true,
// a success response will be produced before the server sees the
// bad chunk header above, making this test fail.
await connection.ReceiveForcedEnd(
"HTTP/1.1 400 Bad Request",
"Connection: close",
$"Date: {server.Context.DateHeaderValue}",
"Content-Length: 0",
"",
"");
await connection.ReceiveEnd();
}
}

Assert.Contains(sink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
&& ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status400BadRequest);
}

[Fact]
Expand Down