akka.net icon indicating copy to clipboard operation
akka.net copied to clipboard

Akka.TestKit: `EventFilter.Expect_Async` waits full `expect-msg-after` period even if internal method has already finished

Open Aaronontheweb opened this issue 1 year ago • 5 comments

Version Information Version of Akka.NET? v1.5.19 and later Which Akka.NET Modules? Akka.TestKit

Describe the bug

Consider the following reproduction test:

public class TimerStartupCrashBugFixSpec : AkkaSpec
{
    public TimerStartupCrashBugFixSpec(ITestOutputHelper output) : base(output: output, Akka.Configuration.Config.Empty)
    {
        Sys.Log.Info("Starting TimerStartupCrashBugFixSpec");
    }
    
    private class TimerActor : UntypedActor, IWithTimers
    {
        public sealed class Check
        {
            public static Check Instance { get; } = new Check();
            private Check() { }
        }
        
        public sealed class Hit
        {
            public static Hit Instance { get; } = new Hit();
            private Hit() { }
        }
        
        private readonly ILoggingAdapter _log = Context.GetLogger();
        private int _counter = 0;
        public ITimerScheduler? Timers { get; set; } = null;

        protected override void PreStart()
        {
            Timers?.StartPeriodicTimer("key", Hit.Instance, TimeSpan.FromMilliseconds(1));
        }

        protected override void OnReceive(object message)
        {
            switch (message)
            {
                case Check _:
                    _log.Info("Check received");
                    Sender.Tell(_counter);
                    break;
                case Hit _:
                    _log.Info("Hit received");
                    _counter++;
                    break;
            }
        }

        protected override void PreRestart(Exception reason, object message)
        {
            _log.Error(reason, "Not restarting - shutting down");
            Context.Stop(Self);
        }
    }
    
    [Fact]
    public async Task TimerActor_should_not_crash_on_startup()
    {
        var actor = Sys.ActorOf(Props.Create(() => new TimerActor()).WithRouter(new RoundRobinPool(10)));
        
        // bug: EventFilter waits full 3 seconds even if the underlying operation completes earlier
        await EventFilter.Exception(typeof(ActorInitializationException)).ExpectAsync(0, async () =>
        {
            var i = 0;
            while (i == 0)
            {
                // guarantee that the actor has started and processed a message from scheduler
                i = await actor.Ask<int>(TimerActor.Check.Instance);
            }
        });
    }
}

i = await actor.Ask<int>(TimerActor.Check.Instance); completes in under 100ms. The test still waits a full 3 seconds to exit.

Expected behavior

The way all of the assertions in the TestKit should be designed is exit as soon as:

  1. The thing being tested has completed successfully OR
  2. The time period has elapsed.

Actual behavior

Right now it looks like we're waiting FOR BOTH of these things to complete. This might be adding significant execution time to the entire Akka.NET test suite.

Aaronontheweb avatar Apr 26 '24 18:04 Aaronontheweb

Are there any other async TestKit methods that behave like this @Arkatufus ?

Aaronontheweb avatar Apr 26 '24 18:04 Aaronontheweb

This is by design, when you set expectedCount in ExpectAsync() to 0, the ExpectAsync() behaves exactly like ExpectNoMsg() because the filter does not know if the async Func<Task<T>> have a side effect that happens in the future.

https://github.com/akkadotnet/akka.net/blob/ba3639e49c528a84ea176b27234c00c9c699d30b/src/core/Akka.TestKit/EventFilter/Internal/EventFilterApplier.cs#L564-L575

To shorten the time, set the timeout value to less than 3 seconds.

Arkatufus avatar Apr 30 '24 16:04 Arkatufus

An improvement to this is to disallow setting expectedCount to 0 and create another event filter method called ExpectNoneAsync() to make this clearer to the user.

Arkatufus avatar Apr 30 '24 16:04 Arkatufus

The reproduction code is slightly suspect, if the unit test is supposed to check that the actor did not crash during startup, then the actor creation itself should be inside the filter. What this unit test testing is checking that the Ask() operation did not time out.

Arkatufus avatar Apr 30 '24 16:04 Arkatufus

The reproduction code is slightly suspect, if the unit test is supposed to check that the actor did not crash during startup, then the actor creation itself should be inside the filter. What this unit test testing is checking that the Ask() operation did not time out.

The Ask operation will time out if the actor fails during startup as it can't process the message when this occurs.

Aaronontheweb avatar May 01 '24 19:05 Aaronontheweb