I'm somewhat confused by 'advanceTimeBy' mechanics...

# coroutines

[Mikołaj Karwowski]

I'm somewhat confused by 'advanceTimeBy' mechanics in kotlin tests using runBlockingTest

Modifying a bit code present here, in the documentation:
https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-test/kotlinx.coroutines.test/-delay-controller/advance-time-by.html

To something like that:

@Test
    fun advanceTimeTest() = runBlockingTest {
        foo()
        advanceTimeBy(2_000)  // advanceTimeBy(2_000) will progress through the first two delays
        println("Main 1")
        // virtual time is 2_000, next resume is at 2_001
        advanceTimeBy(2)      // progress through the last delay of 501 (note 500ms were already advanced)
        println("Main 2")
        // virtual time is 2_0002
    }

    fun CoroutineScope.foo() {
        launch {
            println("Foo 1")
            delay(1_000)    // advanceTimeBy(2_000) will progress through this delay (resume @ virtual time 1_000)
            // virtual time is 1_000
            println("Foo 2")
            delay(500)      // advanceTimeBy(2_000) will progress through this delay (resume @ virtual time 1_500)
            // virtual time is 1_500
            println("Foo 3")
            delay(501)      // advanceTimeBy(2_000) will not progress through this delay (resume @ virtual time 2_001)
            // virtual time is 2_001
        }
    }

The result is:

Foo 1

Foo 2

Foo 3

Main 1

Main 2

Shouldn't it be: Foo1, Foo2, Main1, Foo3, Main2 ?

[Joffrey]

As a rule of thumb, you can consider all non-delay stuff to take 0 virtual time.

Advancing by 2 seconds will bring you almost to the end of the 3rd delay from foo() (it doesn't progress through it completely, but still eats a good deal of it):

println("Foo 1")
delay(1_000)    // advanceTimeBy(2_000) will progress through this delay (resume @ virtual time 1_000)
                // virtual time is 1_000
println("Foo 2")
                // virtual time is 1_000 (still)
delay(500)      // advanceTimeBy(2_000) will progress through this delay (resume @ virtual time 1_500)
                // virtual time is 1_500, so advanceTimeBy(2_000) still has stuff to execute here
println("Foo 3")
                // virtual time is 1_500 (still), so advanceTimeBy(2_000) still has stuff to execute here
delay(501)      // advanceTimeBy(2_000) will progress to 500/501th of this delay and doesn't resume yet

It makes sense to me that all 3 println from foo() go first. You can try to add a 4th println after the delay(501) , it should be printed after Main 1.

Why do you expect Main 1 to be printed before Foo 3?

[Mikołaj Karwowski]

😳
You re so right, I messed up the placement of printlns 🤦‍♂️
I got tangled in testing coroutines and seeing this snippet not work either made me lose faith in myself

Sorry for that, I must be too tired, but I should've checked it better before asking anyway

[Joffrey]

Happens to everyone, there is really no problem is asking. It may actually save you some time 😄