Don't count long tick intervals against rate measurements (#3070)

This might help address #3015

This only affects rate timeouts. Normal fixed timeouts might deserve the same treatment, but that would require some additional locking to ensure we don't modify the sentinel value.
This commit is contained in:
Stephen Halter 2018-11-02 10:58:30 -07:00 committed by GitHub
parent d50c0c13b9
commit f2a383dc76
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 275 additions and 146 deletions

View File

@ -96,7 +96,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
return;
}
_readTimingElapsedTicks += timestamp - _lastTimestamp;
// Assume overly long tick intervals are the result of server resource starvation.
// Don't count extra time between ticks against the rate limit.
_readTimingElapsedTicks += Math.Min(timestamp - _lastTimestamp, Heartbeat.Interval.Ticks);
if (_minReadRate.BytesPerSecond > 0 && _readTimingElapsedTicks > _minReadRate.GracePeriod.Ticks)
{
@ -124,6 +126,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
{
lock (_writeTimingLock)
{
// Assume overly long tick intervals are the result of server resource starvation.
// Don't count extra time between ticks against the rate limit.
var extraTimeForTick = timestamp - _lastTimestamp - Heartbeat.Interval.Ticks;
if (extraTimeForTick > 0)
{
_writeTimingTimeoutTimestamp += extraTimeForTick;
}
if (_concurrentAwaitingWrites > 0 && timestamp > _writeTimingTimeoutTimestamp && !Debugger.IsAttached)
{
_timeoutHandler.OnTimeout(TimeoutReason.WriteDataRate);

View File

@ -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 Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.FlowControl;
using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
using Microsoft.AspNetCore.Testing;
using Moq;
@ -13,11 +14,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
{
private readonly Mock<ITimeoutHandler> _mockTimeoutHandler;
private readonly TimeoutControl _timeoutControl;
private readonly MockSystemClock _systemClock;
public TimeoutControlTests()
{
_mockTimeoutHandler = new Mock<ITimeoutHandler>();
_timeoutControl = new TimeoutControl(_mockTimeoutHandler.Object);
_systemClock = new MockSystemClock();
}
[Fact]
@ -28,7 +31,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.Debugger = mockDebugger.Object;
var now = DateTimeOffset.Now;
_timeoutControl.Tick(now);
_timeoutControl.Initialize(now);
_timeoutControl.SetTimeout(1, TimeoutReason.RequestHeaders);
_timeoutControl.Tick(now.AddTicks(2).Add(Heartbeat.Interval));
@ -64,7 +67,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
// Initialize timestamp
var now = DateTimeOffset.UtcNow;
_timeoutControl.Tick(now);
_timeoutControl.Initialize(now);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
@ -78,7 +81,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Tick after grace period w/ low data rate
now += TimeSpan.FromSeconds(2);
now += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(now);
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(10);
_timeoutControl.Tick(now);
@ -94,13 +99,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
// Initialize timestamp
var now = DateTimeOffset.UtcNow;
_timeoutControl.Tick(now);
_timeoutControl.Initialize(now);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
// Set base data rate to 200 bytes/second
now += gracePeriod;
now += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(now);
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(400);
_timeoutControl.Tick(now);
@ -149,49 +156,54 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
[Fact]
public void RequestBodyDataRateNotComputedOnPausedTime()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Initialize(_systemClock.UtcNow);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
// Tick at 3s, expected counted time is 3s, expected data rate is 200 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(3);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(600);
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Tick(_systemClock.UtcNow);
// Pause at 3.5s
systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_timeoutControl.StopTimingRead();
// Tick at 4s, expected counted time is 4s (first tick after pause goes through), expected data rate is 150 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_timeoutControl.Tick(_systemClock.UtcNow);
// Tick at 6s, expected counted time is 4s, expected data rate is 150 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(2);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(2);
_timeoutControl.Tick(_systemClock.UtcNow);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Resume at 6.5s
systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_timeoutControl.StartTimingRead();
// Tick at 9s, expected counted time is 6s, expected data rate is 100 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(1.5);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1.0);
_timeoutControl.Tick(_systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(.5);
_timeoutControl.Tick(_systemClock.UtcNow);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Tick at 10s, expected counted time is 7s, expected data rate drops below 100 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
// Timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -200,42 +212,43 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
[Fact]
public void ReadTimingNotPausedWhenResumeCalledBeforeNextTick()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Initialize(_systemClock.UtcNow);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
// Tick at 2s, expected counted time is 2s, expected data rate is 100 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(2);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_timeoutControl.BytesRead(200);
_timeoutControl.Tick(systemClock.UtcNow);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Pause at 2.25s
systemClock.UtcNow += TimeSpan.FromSeconds(0.25);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.25);
_timeoutControl.StopTimingRead();
// Resume at 2.5s
systemClock.UtcNow += TimeSpan.FromSeconds(0.25);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.25);
_timeoutControl.StartTimingRead();
// Tick at 3s, expected counted time is 3s, expected data rate is 100 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_systemClock.UtcNow += TimeSpan.FromSeconds(0.5);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Tick(_systemClock.UtcNow);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Tick at 4s, expected counted time is 4s, expected data rate drops below 100 bytes/second
systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(_systemClock.UtcNow);
// Timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -244,14 +257,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
[Fact]
public void ReadTimingNotEnforcedWhenTimeoutIsSet()
{
var systemClock = new MockSystemClock();
var timeout = TimeSpan.FromSeconds(5);
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
var startTime = systemClock.UtcNow;
var startTime = _systemClock.UtcNow;
// Initialize timestamp
_timeoutControl.Tick(startTime);
_timeoutControl.Initialize(startTime);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
@ -259,37 +271,122 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.SetTimeout(timeout.Ticks, TimeoutReason.RequestBodyDrain);
// Tick beyond grace period with low data rate
systemClock.UtcNow += TimeSpan.FromSeconds(3);
_systemClock.UtcNow += TimeSpan.FromSeconds(3);
_timeoutControl.BytesRead(1);
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Tick(_systemClock.UtcNow);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Tick just past timeout period, adjusted by Heartbeat.Interval
systemClock.UtcNow = startTime + timeout + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow = startTime + timeout + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(_systemClock.UtcNow);
// Timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.RequestBodyDrain), Times.Once);
}
[Fact]
public void WriteTimingAbortsConnectionWhenWriteDoesNotCompleteWithMinimumDataRate()
public void ReadTimingNotEnforcedWhenLowConnectionInputFlowControlAvailability()
{
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
var flowControl = new InputFlowControl(initialWindowSize: 2, minWindowSizeIncrement: 1);
// Initialize timestamp
var now = DateTimeOffset.UtcNow;
_timeoutControl.Initialize(now);
_timeoutControl.InitializeHttp2(flowControl);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
// Tick past grace period
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
// Induce low flow control availability
flowControl.TryAdvance(2);
// Read 0 bytes in 1 second
now += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(now);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Relieve low flow control availability
flowControl.TryUpdateWindow(2, out _);
_timeoutControl.Tick(now);
// Still not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Read 0 bytes in 1 second
now += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(now);;
// Timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
}
[Fact]
public void ReadTimingOnlyCountsUpToOneHeartbeatIntervalPerTick()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Tick(systemClock.UtcNow);
var now = DateTimeOffset.UtcNow;
_timeoutControl.Initialize(now);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
// Tick past grace period
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
// Read 100 bytes in 2 seconds with a single tick
now += TimeSpan.FromSeconds(2);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
// Not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Read 100 bytes in 2 seconds in two ticks
now += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(100);
_timeoutControl.Tick(now);
now += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(now);
// Timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
}
[Fact]
public void WriteTimingAbortsConnectionWhenWriteDoesNotCompleteWithMinimumDataRate()
{
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Initialize(_systemClock.UtcNow);
// Should complete within 4 seconds, but the timeout is adjusted by adding Heartbeat.Interval
_timeoutControl.BytesWrittenToBuffer(minRate, 400);
_timeoutControl.StartTimingWrite();
// Tick just past 4s plus Heartbeat.Interval
systemClock.UtcNow += TimeSpan.FromSeconds(4) + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(4) + Heartbeat.Interval + TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
}
@ -297,40 +394,35 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
[Fact]
public void WriteTimingAbortsConnectionWhenSmallWriteDoesNotCompleteWithinGracePeriod()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(5));
// Initialize timestamp
var startTime = systemClock.UtcNow;
_timeoutControl.Tick(startTime);
var startTime = _systemClock.UtcNow;
_timeoutControl.Initialize(startTime);
// Should complete within 1 second, but the timeout is adjusted by adding Heartbeat.Interval
_timeoutControl.BytesWrittenToBuffer(minRate, 100);
_timeoutControl.StartTimingWrite();
// Tick just past 1s plus Heartbeat.Interval
systemClock.UtcNow += TimeSpan.FromSeconds(1) + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1) + Heartbeat.Interval + TimeSpan.FromTicks(1));
// Still within grace period, not timed out
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// Tick just past grace period (adjusted by Heartbeat.Interval)
systemClock.UtcNow = startTime + minRate.GracePeriod + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(minRate.GracePeriod - TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
}
[Fact]
public void WriteTimingTimeoutPushedOnConcurrentWrite()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Tick(systemClock.UtcNow);
_timeoutControl.Initialize(_systemClock.UtcNow);
// Should complete within 5 seconds, but the timeout is adjusted by adding Heartbeat.Interval
_timeoutControl.BytesWrittenToBuffer(minRate, 500);
@ -341,8 +433,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.StartTimingWrite();
// Tick just past 5s plus Heartbeat.Interval, when the first write should have completed
systemClock.UtcNow += TimeSpan.FromSeconds(5) + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(5) + Heartbeat.Interval + TimeSpan.FromTicks(1));
// Not timed out because the timeout was pushed by the second write
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
@ -351,8 +442,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.StopTimingWrite();
// Tick just past +3s, when the second write should have completed
systemClock.UtcNow += TimeSpan.FromSeconds(3) + TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(3));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
}
@ -360,14 +450,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
[Fact]
public void WriteTimingAbortsConnectionWhenRepeatedSmallWritesDoNotCompleteWithMinimumDataRate()
{
var systemClock = new MockSystemClock();
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(5));
var numWrites = 5;
var writeSize = 100;
// Initialize timestamp
var startTime = systemClock.UtcNow;
_timeoutControl.Tick(startTime);
var startTime = _systemClock.UtcNow;
_timeoutControl.Initialize(startTime);
// 5 consecutive 100 byte writes.
for (var i = 0; i < numWrites - 1; i++)
@ -381,14 +470,37 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
// Move the clock forward Heartbeat.Interval + MinDataRate.GracePeriod + 4 seconds.
// The grace period should only be added for the first write. The subsequent 4 100 byte writes should add 1 second each to the timeout given the 100 byte/s min rate.
systemClock.UtcNow += Heartbeat.Interval + minRate.GracePeriod + TimeSpan.FromSeconds((numWrites - 1) * writeSize / minRate.BytesPerSecond);
_timeoutControl.Tick(systemClock.UtcNow);
AdvanceClock(Heartbeat.Interval + minRate.GracePeriod + TimeSpan.FromSeconds((numWrites - 1) * writeSize / minRate.BytesPerSecond));
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
// On more tick forward triggers the timeout.
systemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(systemClock.UtcNow);
_systemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
}
[Fact]
public void WriteTimingOnlyCountsUpToOneHeartbeatIntervalPerTick()
{
var minRate = new MinDataRate(bytesPerSecond: 100, gracePeriod: TimeSpan.FromSeconds(2));
// Initialize timestamp
_timeoutControl.Initialize(_systemClock.UtcNow);
// Should complete within 4 seconds, but the timeout is adjusted by adding Heartbeat.Interval
_timeoutControl.BytesWrittenToBuffer(minRate, 400);
_timeoutControl.StartTimingWrite();
// Tick just past 4s plus Heartbeat.Interval at once
_systemClock.UtcNow += TimeSpan.FromSeconds(4) + Heartbeat.Interval + TimeSpan.FromTicks(1);
_timeoutControl.Tick(_systemClock.UtcNow);
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Never);
// The last Tick only accounted for one heartbeat interval. Try again with a tick per interval.
AdvanceClock(TimeSpan.FromSeconds(4) + TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
}
@ -400,16 +512,31 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
var minRate = new MinDataRate(bytesPerSecond, gracePeriod);
// Initialize timestamp
var now = DateTimeOffset.UtcNow;
_timeoutControl.Tick(now);
_timeoutControl.Initialize(_systemClock.UtcNow);
_timeoutControl.StartRequestBody(minRate);
_timeoutControl.StartTimingRead();
AdvanceClock(gracePeriod);
// Tick after grace period w/ low data rate
now += gracePeriod + TimeSpan.FromSeconds(1);
_systemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.BytesRead(1);
_timeoutControl.Tick(now);
_timeoutControl.Tick(_systemClock.UtcNow);
}
private void AdvanceClock(TimeSpan timeSpan)
{
var endTime = _systemClock.UtcNow + timeSpan;
while (_systemClock.UtcNow + Heartbeat.Interval < endTime)
{
_systemClock.UtcNow += Heartbeat.Interval;
_timeoutControl.Tick(_systemClock.UtcNow);
}
_systemClock.UtcNow = endTime;
_timeoutControl.Tick(_systemClock.UtcNow);
}
}
}

View File

@ -1160,6 +1160,21 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
}
}
protected void AdvanceClock(TimeSpan timeSpan)
{
var clock = _serviceContext.MockSystemClock;
var endTime = clock.UtcNow + timeSpan;
while (clock.UtcNow + Heartbeat.Interval < endTime)
{
clock.UtcNow += Heartbeat.Interval;
_timeoutControl.Tick(clock.UtcNow);
}
clock.UtcNow = endTime;
_timeoutControl.Tick(clock.UtcNow);
}
public class Http2FrameWithPayload : Http2Frame
{
public Http2FrameWithPayload() : base()

View File

@ -30,13 +30,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_connectionTask = _connection.ProcessRequestsAsync(new DummyApplication(_noopApplication));
mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.KeepAliveTimeout + Heartbeat.Interval);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.KeepAlive), Times.Once);
@ -55,13 +53,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await InitializeConnectionAsync(_noopApplication);
mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.KeepAliveTimeout + Heartbeat.Interval);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.KeepAlive), Times.Once);
@ -80,8 +76,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await InitializeConnectionAsync(_noopApplication);
mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.KeepAliveTimeout + Heartbeat.Interval);
// keep-alive timeout set but not fired.
_mockTimeoutControl.Verify(c => c.SetTimeout(It.IsAny<long>(), TimeoutReason.KeepAlive), Times.Once);
@ -113,13 +108,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await setTimeoutTcs.Task.DefaultTimeout();
mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.KeepAliveTimeout + Heartbeat.Interval);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.KeepAlive), Times.Once);
@ -142,15 +135,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await SendEmptyContinuationFrameAsync(1, Http2ContinuationFrameFlags.NONE);
mockSystemClock.UtcNow += limits.RequestHeadersTimeout + Heartbeat.Interval;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.RequestHeadersTimeout + Heartbeat.Interval);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
await SendEmptyContinuationFrameAsync(1, Http2ContinuationFrameFlags.NONE);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.RequestHeaders), Times.Once);
@ -181,17 +172,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await WaitForConnectionStopAsync(expectedLastStreamId: 0, ignoreNonGoAwayFrames: false);
mockSystemClock.UtcNow +=
TimeSpan.FromSeconds(_bytesReceived / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(_bytesReceived / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5));
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
_mockConnectionContext.Verify(c => c.Abort(It.IsAny<ConnectionAbortedException>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -285,16 +272,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.Tick(mockSystemClock.UtcNow);
// Don't read data frame to induce "socket" backpressure.
mockSystemClock.UtcNow +=
TimeSpan.FromSeconds((_bytesReceived + _helloWorldBytes.Length) / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds((_bytesReceived + _helloWorldBytes.Length) / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5));
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -348,13 +331,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
// Don't read data frame to induce "socket" backpressure.
mockSystemClock.UtcNow += timeToWriteMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToWriteMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -409,16 +390,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
_timeoutControl.Tick(mockSystemClock.UtcNow);
// Don't send WINDOW_UPDATE to induce flow-control backpressure
mockSystemClock.UtcNow +=
TimeSpan.FromSeconds(_bytesReceived / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(_bytesReceived / limits.MinResponseDataRate.BytesPerSecond) +
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5));
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -470,13 +447,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
// Don't send WINDOW_UPDATE to induce flow-control backpressure
mockSystemClock.UtcNow += timeToWriteMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToWriteMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -540,14 +515,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
limits.MinResponseDataRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
// Don't send WINDOW_UPDATE to induce flow-control backpressure
mockSystemClock.UtcNow += timeToWriteMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToWriteMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
//mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once);
@ -592,13 +564,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
withStreamId: 1);
// Don't send any more data and advance just to and then past the grace period.
mockSystemClock.UtcNow += limits.MinRequestBodyDataRate.GracePeriod;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.MinRequestBodyDataRate.GracePeriod);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -647,13 +617,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
var timeToReadMaxData = TimeSpan.FromSeconds(_maxData.Length / limits.MinRequestBodyDataRate.BytesPerSecond) - TimeSpan.FromSeconds(.5);
// Don't send any more data and advance just to and then past the rate timeout.
mockSystemClock.UtcNow += timeToReadMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToReadMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -718,13 +686,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
timeToReadMaxData -= TimeSpan.FromSeconds(.5);
// Don't send any more data and advance just to and then past the rate timeout.
mockSystemClock.UtcNow += timeToReadMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToReadMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -790,13 +756,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
var timeToReadMaxData = TimeSpan.FromSeconds(_maxData.Length / limits.MinRequestBodyDataRate.BytesPerSecond) - TimeSpan.FromSeconds(.5);
// Don't send any more data and advance just to and then past the rate timeout.
mockSystemClock.UtcNow += timeToReadMaxData;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(timeToReadMaxData);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromSeconds(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);
@ -863,8 +827,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
withStreamId: 3);
// No matter how much time elapses there is no read timeout because the connection window is too small.
mockSystemClock.UtcNow += TimeSpan.FromDays(365);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromDays(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
@ -885,13 +848,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
withFlags: (byte)Http2DataFrameFlags.NONE,
withStreamId: 0);
mockSystemClock.UtcNow += limits.MinRequestBodyDataRate.GracePeriod;
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(limits.MinRequestBodyDataRate.GracePeriod);
_mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny<TimeoutReason>()), Times.Never);
mockSystemClock.UtcNow += TimeSpan.FromTicks(1);
_timeoutControl.Tick(mockSystemClock.UtcNow);
AdvanceClock(TimeSpan.FromTicks(1));
_mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.ReadDataRate), Times.Once);

View File

@ -71,8 +71,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests
await appRunningEvent.Task.DefaultTimeout();
serviceContext.MockSystemClock.UtcNow += gracePeriod + TimeSpan.FromSeconds(1);
heartbeatManager.OnHeartbeat(serviceContext.SystemClock.UtcNow);
// Advance the clock gracePeriod + TimeSpan.FromSeconds(1)
for (var i = 0; i < 6; i++)
{
serviceContext.MockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
heartbeatManager.OnHeartbeat(serviceContext.SystemClock.UtcNow);
}
await connection.Receive(
"HTTP/1.1 408 Request Timeout",
@ -184,8 +188,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests
await appRunningTcs.Task.DefaultTimeout();
serviceContext.MockSystemClock.UtcNow += gracePeriod + TimeSpan.FromSeconds(1);
heartbeatManager.OnHeartbeat(serviceContext.SystemClock.UtcNow);
// Advance the clock gracePeriod + TimeSpan.FromSeconds(1)
for (var i = 0; i < 6; i++)
{
serviceContext.MockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
heartbeatManager.OnHeartbeat(serviceContext.SystemClock.UtcNow);
}
await exceptionSwallowedTcs.Task.DefaultTimeout();

View File

@ -59,7 +59,14 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
// Wait for the drain timeout to be set.
await outputBufferedTcs.Task.DefaultTimeout();
testContext.MockSystemClock.UtcNow += minRate.GracePeriod + Heartbeat.Interval - TimeSpan.FromSeconds(.5);
// Advance the clock to the grace period
for (var i = 0; i < 2; i++)
{
testContext.MockSystemClock.UtcNow += TimeSpan.FromSeconds(1);
heartbeatManager.OnHeartbeat(testContext.SystemClock.UtcNow);
}
testContext.MockSystemClock.UtcNow += Heartbeat.Interval - TimeSpan.FromSeconds(.5);
heartbeatManager.OnHeartbeat(testContext.SystemClock.UtcNow);
Assert.Null(transportConnection.AbortReason);