Hi, I have a problem with simple experiment code to play with coroutines stdlib api (

startCoroutine

and

suspendCoroutine

) My example code is:

val String.p get() = println("Coroutines Intro [${getCurrentTimeString()}] $this")

        val scheduler = Executors.newSingleThreadScheduledExecutor()
        
        val mydelay: suspend Unit.(time: Long) -> Unit = { time ->
            suspendCoroutine<Unit> { continuation ->
                scheduler.schedule( { continuation.resume(Unit) }, time, TimeUnit.MILLISECONDS)
            }
        }

        val coroutine: suspend Unit.() -> Unit = {
            "coroutine start".p
            mydelay(1000)
            "coroutine middle".p
            mydelay(1000)
            "coroutine end".p
        }

        val completion = object : Continuation<Unit> {
            override val context = EmptyCoroutineContext
            override fun resume(value: Unit) { "completion: completed normally".p }
            override fun resumeWithException(exception: Throwable) { "completion: exception: $exception".p }
        }

        "main: start".p
        coroutine.startCoroutine(Unit, completion)
        "main: after startCoroutine".p
        Thread.sleep(3000)
        "main: after sleep 3000".p

The problem is that it logs too much, but if I change

mydelay(1000)

to

delay(1000)

(from kotlinx.coroutines), then it works just fine... The exact (and correct) output in case of

delay(1000)

is:

Coroutines Intro [16:29:19:231] main: start
Coroutines Intro [16:29:19:244] coroutine start
Coroutines Intro [16:29:19:269] main: after startCoroutine
Coroutines Intro [16:29:20:264] coroutine middle
Coroutines Intro [16:29:21:265] coroutine end
Coroutines Intro [16:29:21:265] completion: completed normally
Coroutines Intro [16:29:22:269] main: after sleep 3000

And (incorrect) output in case of my own

mydelay(1000)

is:

Coroutines Intro [16:31:59:864] main: start
Coroutines Intro [16:31:59:874] coroutine start
Coroutines Intro [16:31:59:878] coroutine middle
Coroutines Intro [16:31:59:879] coroutine end
Coroutines Intro [16:31:59:879] completion: completed normally
Coroutines Intro [16:31:59:879] main: after startCoroutine
Coroutines Intro [16:32:00:877] coroutine end
Coroutines Intro [16:32:00:878] completion: completed normally
Coroutines Intro [16:32:00:879] coroutine end
Coroutines Intro [16:32:00:879] completion: completed normally
Coroutines Intro [16:32:01:877] coroutine end
Coroutines Intro [16:32:01:878] completion: completed normally
Coroutines Intro [16:32:01:879] coroutine end
Coroutines Intro [16:32:01:880] completion: completed normally
Coroutines Intro [16:32:02:878] coroutine end
Coroutines Intro [16:32:02:879] completion: completed normally
Coroutines Intro [16:32:02:879] coroutine end
Coroutines Intro [16:32:02:880] main: after sleep 3000
Coroutines Intro [16:32:02:880] completion: completed normally

Does anybody see what is wrong with this example?