Why is Task.Delay(1) necessary to advance clock when unit testing with .NET TimeProvider?

157 views Asked by At

I have configured a retry based pipeline with Polly.

// Using Polly for retry logic
private readonly ResiliencePipeline _retryPipeline = new ResiliencePipelineBuilder { TimeProvider = timeProvider }
    .AddRetry(new RetryStrategyOptions
    {
        ShouldHandle = new PredicateBuilder().Handle<ConditionalCheckFailedException>(),
        Delay = TimeSpan.FromMilliseconds(_backoffFactor),
        MaxRetryAttempts = _maxAttempts - 1,

        // Linear backoff increases the delay each time by the backoff factor
        BackoffType = DelayBackoffType.Linear,
        OnRetry = onRetryArguments =>
        {
            logger.LogWarning(
                "Failed to acquire lock. Retrying. {@LogContext}",
                new { onRetryArguments });
            return ValueTask.CompletedTask;
        }
    })
    .Build();

Which I execute using

// Attempt to store the lock with backoff retry 
LockResult result = await _retryPipeline.ExecuteAsync(
   async _ => await AttemptLockStorageAsync(lockId, expiryMilliseconds, attempts++),
   cancellationTokenSource.Token);

When unit testing, I find that I have to add a Task.Delay(1) in order for Polly to perform the retries

// Act
Func<Task<DistributedLock>> func = async () =>
{
    Task<DistributedLock> result = _distributedLockService.AcquireLockAsync(lockId);
    for (int i = 1; i <= 4; i++)
    {
        _timeProvider.Advance(TimeSpan.FromMilliseconds(1000 * i + 1));
        await Task.Delay(1);
    }

    return await result;
};

// Assert
// We expect that we should be able to attempt 5 full times, rather than getting a TaskCancelledException.
(await func.Should().ThrowAsync<TimeoutException>()).WithMessage(
    $"Could not acquire lock {lockId}. Attempted 5 times.");

Why is the Task.Delay necessary?

Edit

TimeProvider provided to the SUT via the primary constructor.

public class DistributedLockService(
    IDistributedLockRepository distributedLockRepository,
    ILogger<DistributedLockService> logger,
    TimeProvider timeProvider)
    : IDisposable, IDistributedLockService

FakeTimer is provided in the unit test constructor

    private readonly FakeTimeProvider _timeProvider = new();

    public DistributedLockServiceTests()
    {
        _timeProvider.SetUtcNow(DateTimeOffset.Parse("2024-01-23", CultureInfo.InvariantCulture));
        _distributedLockService = new DistributedLockService(
            _distributedLockRepository.Object,
            _logger.Object,
            _timeProvider);
    }

Filed a bug report based on minimal reproduction https://github.com/App-vNext/Polly/issues/1932

1

There are 1 answers

4
Peter Csala On

First let me show you the working code

//Arrange
var delays = new List<TimeSpan>();
var timeProvider = new FakeTimeProvider();
var sut = new ResiliencePipelineBuilder { TimeProvider = timeProvider }
.AddRetry(new RetryStrategyOptions
{
    ShouldHandle = _ => new ValueTask<bool>(true),
    Delay = TimeSpan.FromSeconds(2),
    MaxRetryAttempts = 3,
    BackoffType = DelayBackoffType.Linear,
    OnRetry = args =>
    {
        delays.Add(args.RetryDelay);
        return default;
    }
})
.Build();

//Act
var executing = sut.ExecuteAsync(_ => new ValueTask<int>(0)).AsTask();
while (!executing.IsCompleted)
{
    timeProvider.Advance(TimeSpan.FromSeconds(1));
}

await executing;

//Assert
Assert.Collection(
    delays, 
    item => Assert.Equal(TimeSpan.FromSeconds(2), item),
    item => Assert.Equal(TimeSpan.FromSeconds(4), item),
    item => Assert.Equal(TimeSpan.FromSeconds(6), item)
);

The trick here is the following: call the Advance in a while loop not in a for loop.

To test failure scenario the Act part needs to be adjusted like this

Task executing = sut.ExecuteAsync(_ => throw new Exception()).AsTask();
while (!executing.IsFaulted)
{
    timeProvider.Advance(TimeSpan.FromSeconds(1));
}

await Assert.ThrowsAsync<Exception>(() => executing);