Skip to content
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
18 changes: 16 additions & 2 deletions src/CommonLib/AdaptiveTimeout.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,10 +14,12 @@ public sealed class AdaptiveTimeout : IDisposable {
private readonly ConcurrentQueue<DateTime> _latestSuccessTimestamps;
private readonly ILogger _log;
private readonly TimeSpan _maxTimeout;
private readonly TimeSpan _minTimeout;
private readonly bool _useAdaptiveTimeout;
private readonly int _minSamplesForAdaptiveTimeout;
private readonly bool _throwIfExcessiveTimeouts;
private int _timeSpikeDecay;
private readonly TimeSpan _defaultMinTimeout = TimeSpan.FromSeconds(1);
private const int TimeSpikePenalty = 2;
private const int TimeSpikeForgiveness = 1;
private const int TimeSpikeThreshold = 3;
Expand All @@ -37,6 +39,7 @@ public AdaptiveTimeout(TimeSpan maxTimeout, ILogger log, int sampleCount = 100,
if (log == null)
throw new ArgumentNullException(nameof(log));

_minTimeout = _defaultMinTimeout;
_sampler = new ExecutionTimeSampler(log, sampleCount, logFrequency);
_latestSuccessTimestamps = new ConcurrentQueue<DateTime>();
_log = log;
Expand All @@ -46,6 +49,16 @@ public AdaptiveTimeout(TimeSpan maxTimeout, ILogger log, int sampleCount = 100,
_throwIfExcessiveTimeouts = throwIfExcessiveTimeouts;
}

public AdaptiveTimeout(TimeSpan maxTimeout, TimeSpan minTimeout, ILogger log, int sampleCount = 100, int logFrequency = 1000, int minSamplesForAdaptiveTimeout = 30, bool useAdaptiveTimeout = true, bool throwIfExcessiveTimeouts = false)
: this(maxTimeout, log, sampleCount, logFrequency, minSamplesForAdaptiveTimeout, useAdaptiveTimeout, throwIfExcessiveTimeouts) {
if (minTimeout < TimeSpan.Zero)
throw new ArgumentException("minTimeout must be non-negative", nameof(minTimeout));
if (minTimeout >= maxTimeout)
throw new ArgumentException("minTimeout must be less than maxTimeout", nameof(minTimeout));

_minTimeout = minTimeout;
}

public void ClearSamples() {
Interlocked.Exchange(ref _timeSpikeDecay, 0);
_sampler.ClearSamples();
Expand Down Expand Up @@ -214,11 +227,11 @@ public void Dispose() {
_sampler.Dispose();
}

// Within 5 standard deviations will have a conservative lower bound of catching 96% of executions (1 - 1/5^2),
// Within 7 standard deviations will have a conservative lower bound of catching 98% of executions (1 - 1/7^2),
// regardless of sample shape
// so long as those samples are independent and identically distributed
// (and if they're not, our TimeSpikeSafetyValve should provide us with some adaptability)
// But the effective collection rate is probably closer to 98+%
// But the effective collection rate is probably closer to 99+%
// (in part because we don't need to filter out "too fast" outliers)
// But we'll cap at configured maximum timeout
// https://modelassist.epixanalytics.com/space/EA/26574957/Tchebysheffs+Rule
Expand All @@ -231,6 +244,7 @@ public TimeSpan GetAdaptiveTimeout() {
var stdDev = _sampler.StandardDeviation();
var adaptiveTimeoutMs = _sampler.Average() + (stdDev * StdDevMultiplier);
var cappedTimeoutMS = Math.Min(adaptiveTimeoutMs, _maxTimeout.TotalMilliseconds);
cappedTimeoutMS = Math.Max(cappedTimeoutMS, _minTimeout.TotalMilliseconds);
return TimeSpan.FromMilliseconds(cappedTimeoutMS);
}
catch (Exception ex) {
Expand Down
3 changes: 2 additions & 1 deletion src/CommonLib/Processors/LocalGroupProcessor.cs
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,8 @@ public LocalGroupProcessor(ILdapUtils utils, ILogger log = null) {
_openDomainAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMServer.OpenDomain)));
_getAliasesAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMDomain.GetAliases)));
_openAliasAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMDomain.OpenAlias)));
_getMembersAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMAlias.GetMembers)));
// Disabling adaptive timeout for GetMembers as it can be very chatty and we don't want timeouts to cause us to miss groups entirely. We can re-enable adaptive timeouts here in the future if we find a good way to handle timeouts without losing entire groups
_getMembersAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMAlias.GetMembers)), useAdaptiveTimeout: false);
_lookupPrincipalBySidAdaptiveTimeout = new AdaptiveTimeout(maxTimeout: TimeSpan.FromMinutes(2), Logging.LogProvider.CreateLogger(nameof(ISAMServer.LookupPrincipalBySid)));
}

Expand Down
34 changes: 27 additions & 7 deletions test/unit/AdaptiveTimeoutTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,8 @@ public AdaptiveTimeoutTest(ITestOutputHelper testOutputHelper) {
[Fact]
public async Task AdaptiveTimeout_GetAdaptiveTimeout_NotEnoughSamplesAsync() {
var maxTimeout = TimeSpan.FromSeconds(1);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3);
var minTimeout = TimeSpan.Zero;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3);

await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(50));

Expand All @@ -29,7 +30,8 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_NotEnoughSamplesAsync() {
[Fact]
public async Task AdaptiveTimeout_GetAdaptiveTimeout_AdaptiveDisabled() {
var maxTimeout = TimeSpan.FromSeconds(1);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3, false);
var minTimeout = TimeSpan.Zero;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3, false);

await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(50));
await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(50));
Expand All @@ -42,7 +44,8 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_AdaptiveDisabled() {
[Fact]
public async Task AdaptiveTimeout_GetAdaptiveTimeout() {
var maxTimeout = TimeSpan.FromSeconds(1);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3);
var minTimeout = TimeSpan.Zero;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 10, 1000, 3);

await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(40));
await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(50));
Expand All @@ -56,8 +59,9 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout() {
public async Task AdaptiveTimeout_GetAdaptiveTimeout_TimeSpikeSafetyValve() {
var tasks = new List<Task>();
var maxTimeout = TimeSpan.FromSeconds(1);
var minTimeout = TimeSpan.Zero;
var numSamples = 30;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 10);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 10);

for (int i = 0; i < numSamples; i++)
tasks.Add(adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(10)));
Expand All @@ -75,8 +79,9 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_TimeSpikeSafetyValve() {
public async Task AdaptiveTimeout_GetAdaptiveTimeout_TimeSpikeSafetyValve_IgnoreHiccup() {
var tasks = new List<Task>();
var maxTimeout = TimeSpan.FromSeconds(1);
var minTimeout = TimeSpan.Zero;
var numSamples = 5;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2);

// Prepare our successful samples
for (int i = 0; i < numSamples; i++)
Expand All @@ -103,8 +108,9 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_TimeSpikeSafetyValve_Ignore
public async Task AdaptiveTimeout_GetAdaptiveTimeout_ThrowWhenExcessiveTimeouts() {
var tasks = new List<Task>();
var maxTimeout = TimeSpan.FromMilliseconds(500);
var minTimeout = TimeSpan.Zero;
var numSamples = 5;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2, throwIfExcessiveTimeouts: true);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2, throwIfExcessiveTimeouts: true);

for (int i = 0; i < numSamples; i++)
tasks.Add(adaptiveTimeout.ExecuteWithTimeout((_) => Task.CompletedTask));
Expand All @@ -121,8 +127,9 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_ThrowWhenExcessiveTimeouts(
public async Task AdaptiveTimeout_GetAdaptiveTimeout_DoNotThrowWhenExcessiveTimeouts() {
var tasks = new List<Task>();
var maxTimeout = TimeSpan.FromMilliseconds(500);
var minTimeout = TimeSpan.Zero;
var numSamples = 5;
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2, throwIfExcessiveTimeouts: false);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), numSamples, 1000, 2, throwIfExcessiveTimeouts: false);

for (int i = 0; i < numSamples; i++)
tasks.Add(adaptiveTimeout.ExecuteWithTimeout((_) => Task.CompletedTask));
Expand All @@ -135,6 +142,19 @@ public async Task AdaptiveTimeout_GetAdaptiveTimeout_DoNotThrowWhenExcessiveTime
await Task.WhenAll(tasks);
}

[Fact]
public async Task AdaptiveTimeout_GetAdaptiveTimeout_MinTimeout() {
var maxTimeout = TimeSpan.FromSeconds(1);
var minTimeout = TimeSpan.FromSeconds(0.5);
var adaptiveTimeout = new AdaptiveTimeout(maxTimeout, minTimeout, new TestLogger(_testOutputHelper, Microsoft.Extensions.Logging.LogLevel.Trace), 1, 1000, 1);

await adaptiveTimeout.ExecuteWithTimeout(async (_) => await Task.Delay(50));

var adaptiveTimeoutResult = adaptiveTimeout.GetAdaptiveTimeout();
Assert.Equal(minTimeout, adaptiveTimeoutResult);
Assert.True(adaptiveTimeoutResult < maxTimeout);
}

[Fact]
public void AdaptiveTimeout_AtomicDecrementWithFloor_IsThreadSafe() {
int value = 1000;
Expand Down
Loading