Akka: ExplicitlyTriggeredScheduler does not cancel tasks in Akka Testkit

Created on 12 Feb 2020  路  3Comments  路  Source: akka/akka

Hi,

In Akka Testkit, there's ExplicitlyTriggeredScheduler, that allows to test scheduling logic by moving in time.

The problem is, that when a task is scheduled, then it's impossible to cancel it. See the following snippet:

object MinimalExample extends App {
  val scheduler = new ExplicitlyTriggeredScheduler(null, printlnAdapter, null)
  val task = scheduler.schedule(1.seconds, 1.second)(println("Hello world!"))(Implicits.global)

  scheduler.timePasses(10 seconds)
  println(task.cancel())
  scheduler.timePasses(10 seconds)

  // doesn't matter...
  lazy val printlnAdapter = new LoggingAdapter {
    override def isErrorEnabled: Boolean = false
    override def isWarningEnabled: Boolean = false
    override def isInfoEnabled: Boolean = false
    override def isDebugEnabled: Boolean = true
    override protected def notifyError(message: String): Unit = println(message)
    override protected def notifyError(cause: Throwable, message: String): Unit = println(message)
    override protected def notifyWarning(message: String): Unit = println(message)
    override protected def notifyInfo(message: String): Unit = println(message)
    override protected def notifyDebug(message: String): Unit = println(message)
  }
}

Output:

Scheduled item for 1000: Item(1000,Some(1 second),akka.actor.Scheduler$$anon$2@1c72da34)
Time proceeds from 0 to 10000, currently scheduled for this period:List(
- Item(1000,Some(1 second),akka.actor.Scheduler$$anon$2@1c72da34))
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
false // println(task.cancel())
Time proceeds from 10000 to 20000, currently scheduled for this period:List(
- Item(11000,Some(1 second),akka.actor.Scheduler$$anon$2@1c72da34))
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!

As you can see task.cancel() returns false, meaning, that canceling was unsuccessful. Job execution does not stop.

Expected output would be:

Scheduled item for 1000: Item(Some(1 second),akka.actor.Scheduler$$anon$2@6b67034)
Time proceeds from 0 to 10000, currently scheduled for this period:List(
- (Item(Some(1 second),akka.actor.Scheduler$$anon$2@6b67034),1000))
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
Hello world!
true
Time proceeds from 10000 to 20000, currently scheduled for this period:List()

I'm using Akka 2.5.27, but the same behavior can be observed on 2.5.29 and 2.6.3.

Let me know what do you think. I'd be more than happy to create a PR with the fix.

1 - triaged testing

Most helpful comment

That's interesting - there does seem to be some logic there to remove it from the scheduled items, so not sure what's going wrong there. It'd be great if you could look into that!

Hi @raboof , let me try to answer this one.

Whenever we want to pass some time, executeTasks gets invoked. It goes through all scheduled tasks in the scheduled map and, for each task:

  1. Removes the task from the map,
  2. Inserts a copy of the task with incremented time to the map.

Now let's say we schedule a task T, then pass some time, and then we want to cancel it. Invoking cancel() on T attempts to remove it from scheduled map. But T is no longer in the map; when the time was passed, T was removed, and its copy with incremented time (let's call it T') has been inserted instead.

So now we are forever stuck with a stale reference to an already-cancelled task T, unable to cancel its successor T'. If we again pass some time, T' will be removed, but T'' will be scheduled, and so on. This effectively makes it seem in our test as if our original task T keeps running on every time tick, even though we wanted to cancel it.

All 3 comments

That's interesting - there does seem to be some logic there to remove it from the scheduled items, so not sure what's going wrong there. It'd be great if you could look into that!

That's interesting - there does seem to be some logic there to remove it from the scheduled items, so not sure what's going wrong there. It'd be great if you could look into that!

Hi @raboof , let me try to answer this one.

Whenever we want to pass some time, executeTasks gets invoked. It goes through all scheduled tasks in the scheduled map and, for each task:

  1. Removes the task from the map,
  2. Inserts a copy of the task with incremented time to the map.

Now let's say we schedule a task T, then pass some time, and then we want to cancel it. Invoking cancel() on T attempts to remove it from scheduled map. But T is no longer in the map; when the time was passed, T was removed, and its copy with incremented time (let's call it T') has been inserted instead.

So now we are forever stuck with a stale reference to an already-cancelled task T, unable to cancel its successor T'. If we again pass some time, T' will be removed, but T'' will be scheduled, and so on. This effectively makes it seem in our test as if our original task T keeps running on every time tick, even though we wanted to cancel it.

Hi @raboof
The fix is ready: https://github.com/akka/akka/pull/28614

Was this page helpful?
0 / 5 - 0 ratings

Related issues

taigua picture taigua  路  3Comments

Daxten picture Daxten  路  3Comments

patriknw picture patriknw  路  3Comments

armanbilge picture armanbilge  路  3Comments

johanandren picture johanandren  路  3Comments