Skip to content
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

Should TimeProviderTaskExtensions run continuations synchronously? #85326

Closed
egil opened this issue Apr 25, 2023 · 7 comments · Fixed by #90489
Closed

Should TimeProviderTaskExtensions run continuations synchronously? #85326

egil opened this issue Apr 25, 2023 · 7 comments · Fixed by #90489

Comments

@egil
Copy link

egil commented Apr 25, 2023

From a test ergonomics point of view, having the backward-compatible TimeProvider extensions methods run continuations asynchronously is bad for business.

I have a ManualTimeProvider implementation I am currently using included in https://github.com/egil/TimeScheduler, where I ported the TimeProvider type to .NET 6 as well as the TimeProviderTaskExtensions type. However, in my implementation, I changed the following:

public DelayState() : base(TaskCreationOptions.RunContinuationsAsynchronously) {}

to

public DelayState() : base() { }

This allows me to write the following test:

[Fact]
public void Callbacks_runs_synchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, () => callbackCount++);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));

    // assert
    callbackCount.Should().Be(1);

    static async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        await timeProvider.Delay(TimeSpan.FromSeconds(10));
        callback();
    }
}

With the original version that uses TaskCreationOptions.RunContinuationsAsynchronously, I have to add a Task.Yield() or similar into the test after forwarding time, otherwise the test will fail.

[Fact]
public async void Callbacks_runs_asynchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, () => callbackCount++);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));
+    await Task.Yield();

    // assert
    callbackCount.Should().Be(1);

    static async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        await timeProvider.Delay(TimeSpan.FromSeconds(10));
        callback();
    }
}

It is a small change, but it does make the test less readable, adds noise, and more importantly, makes the test non-deterministic.

cc. @tarekgh.

@dotnet-issue-labeler dotnet-issue-labeler bot added the needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners label Apr 25, 2023
@ghost ghost added the untriaged New issue has not been triaged by the area owner label Apr 25, 2023
@tarekgh tarekgh added area-System.DateTime and removed needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners labels Apr 25, 2023
@tarekgh tarekgh added this to the 8.0.0 milestone Apr 25, 2023
@ghost
Copy link

ghost commented Apr 25, 2023

Tagging subscribers to this area: @dotnet/area-system-datetime
See info in area-owners.md if you want to be subscribed.

Issue Details

From a test ergonomics point of view, having the backward-compatible TimeProvider extensions methods run continuations asynchronously is bad for business.

I have a ManualTimeProvider implementation I am currently using included in https://github.com/egil/TimeScheduler, where I ported the TimeProvider type to .NET 6 as well as the TimeProviderTaskExtensions type. However, in my implementation, I changed the following:

public DelayState() : base(TaskCreationOptions.RunContinuationsAsynchronously) {}

to

public DelayState() : base() { }

This allows me to write the following test:

[Fact]
public void Callbacks_runs_synchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, () => callbackCount++);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));

    // assert
    callbackCount.Should().Be(1);

    static async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        await timeProvider.Delay(TimeSpan.FromSeconds(10));
        callback();
    }
}

With the original version that uses TaskCreationOptions.RunContinuationsAsynchronously, I have to add a Task.Yield() or similar into the test after forwarding time, otherwise the test will fail.

[Fact]
public async void Callbacks_runs_asynchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, () => callbackCount++);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));
+    await Task.Yield();

    // assert
    callbackCount.Should().Be(1);

    static async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        await timeProvider.Delay(TimeSpan.FromSeconds(10));
        callback();
    }
}

It is a small change, but it does make the test less readable, adds noise, and more importantly, makes the test non-deterministic.

cc. @tarekgh.

Author: egil
Assignees: -
Labels:

untriaged, area-System.DateTime

Milestone: -

@ghost ghost removed the untriaged New issue has not been triaged by the area owner label Apr 25, 2023
@tarekgh
Copy link
Member

tarekgh commented Apr 25, 2023

CC @stephentoub

@egil
Copy link
Author

egil commented May 19, 2023

I have continued to experiment with this, and I do think there is a difference here that needs to be addressed after trying out the preview 4 release of .NET 8 and the back-compatible package Microsoft.Bcl.TimeProvider.

These two tests fail on .NET6 and net standard 2.0 which uses the down-level package Microsoft.Bcl.TimeProvider, but passes on .NET 8 which does not.

// https://github.com/egil/TimeScheduler/blob/utilize-net8-lib/test/TimeProviderExtensions.Tests/ManualTimeProviderTests.cs#LL27C5-L73C6
[Fact]
public void Delay_callbacks_runs_synchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, null);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));

    // assert
    callbackCount.Should().Be(1);

    async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        await timeProvider.Delay(TimeSpan.FromSeconds(10));
        callback();
    }
}

[Fact]
public void WaitAsync_callbacks_runs_synchronously()
{
    // arrange
    var sut = new ManualTimeProvider();
    var callbackCount = 0;
    _ = Continuation(sut, null);

    // act
    sut.ForwardTime(TimeSpan.FromSeconds(10));

    // assert
    callbackCount.Should().Be(1);

    async Task Continuation(TimeProvider timeProvider, Action callback)
    {
        try
        {
            await Task.Delay(TimeSpan.FromDays(1)).WaitAsync(TimeSpan.FromSeconds(10), timeProvider);
        }
        catch (TimeoutException)
        {
            callback();
        }
    }
}

The tests pass in both .NET 8 and .NET 6 if I add a await Task.Delay(1) right after sut.ForwardTime(TimeSpan.FromSeconds(10));.

I think they should behave the same, but I recognize that there may be things related to how I have implemented my ManualTimer that could influence things. Here is the implementation of that and my ManualTimeProvider.

@egil
Copy link
Author

egil commented May 19, 2023

Perhaps related: A similar issue is visible with PeriodicTimer, although that does only apply to PeriodicTimer that is supported in .NET 8.

The following test code will fail if periodicTimer.WaitForNextTickAsync(CancellationToken.None) is not followed by .ConfigureAwait(false) in the helper method WaitForNextTickInLoop below the test.

[Theory]
[InlineData(1)]
[InlineData(2)]
[InlineData(3)]
public void PeriodicTimer_WaitForNextTickAsync_completes_iterations(int expectedCallbacks)
{
    var sut = new ManualTimeProvider();
    var calledTimes = 0;
    var interval = TimeSpan.FromSeconds(1);
    var looper = WaitForNextTickInLoop(sut, () => calledTimes++, interval);

    sut.ForwardTime(interval * expectedCallbacks);

    calledTimes.Should().Be(expectedCallbacks);
}

private static async Task WaitForNextTickInLoop(TimeProvider scheduler, Action callback, TimeSpan interval)
{
    using var periodicTimer = scheduler.CreatePeriodicTimer(interval);
    while (await periodicTimer.WaitForNextTickAsync(CancellationToken.None).ConfigureAwait(false))
    {
        callback();
    }
}

@tarekgh
Copy link
Member

tarekgh commented May 19, 2023

Thanks @egil for the info, this is very helpful. We'll look at this issue at some point.

@pharring
Copy link
Contributor

Suggestion: Make ManualTimeProvider.ForwardTime async (Task-returning) and have it yield.

@egil
Copy link
Author

egil commented May 22, 2023

Suggestion: Make ManualTimeProvider.ForwardTime async (Task-returning) and have it yield.

@pharring I tried adding a Thread.Sleep(1); in ForwardTime and that does make Delay_callbacks_runs_synchronously above pass in .NET 6 pass as well.

However, if I also change Delay_callbacks_runs_synchronously to emulate a long-running operation after the Delay call, it only passes in .NET 8 and not in .NET 6.

  [Fact]
  public async Task Delay_callbacks_runs_synchronously()
  {
      // arrange
      var sut = new ManualTimeProvider();
      var callbackCount = 0;
      var continuationTask = Continuation(sut, () => callbackCount++);

      // act
      sut.ForwardTime(TimeSpan.FromSeconds(10));

      // assert
      callbackCount.Should().Be(1);
      await continuationTask;

      static async Task Continuation(TimeProvider timeProvider, Action callback)
      {
          await timeProvider.Delay(TimeSpan.FromSeconds(10));

+         // emulate stuff taking a long time
+         Thread.Sleep(100);

          callback();
      }
  }

So adding a sleep or yield in ForwardTime moves the goal post, but it doesn't solve the problem that there is a difference in behavior between .NET 8 and older versions.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Aug 13, 2023
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 14, 2023
@ghost ghost locked as resolved and limited conversation to collaborators Sep 14, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants