Coroutines println() output not overlapped


#1

My code resemble something like this

fun main(args: Array<String>) = initialize {
    0..100.map {
        async { 
            println("$it: started")
            //... execution that takes random time ...
            println("$it: finished")
        }
    }
    .forEach { it.await() }
    return@initialize
}

fun <T> initialize(block: suspend CoroutineScope.() -> T) = runBlocking {
    //...some stuff...
    val res: T = block()
    //... some other stuff...
    return@runBlocking res
}

The output is not overlapping:

0: started
0: finished
1: started
1: finished
...

How is this possible? I suspect I am doing no parallel computation at all. Using kotlinx-coroutines-core:1.0.0-RC1 but I was having the same behaviour even with previous versions.


#2

This is your code, I just reduced the number of coroutines from 0..100 to 0..10 to have a smaller output and fixed some errors so it can compile:

import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.async
import kotlinx.coroutines.delay
import kotlinx.coroutines.runBlocking
import kotlin.random.Random

fun main() = initialize {
    (0..10).map {
        async {
            println("$it: started")
            delay(Random.nextLong(100, 1000)) // Simulate workload
            println("$it: finished")
        }
    }.forEach { it.await() }
    return@initialize
}

fun <T> initialize(block: suspend CoroutineScope.() -> T) = runBlocking {
    // ... some stuff ...
    val res: T = block()
    // ... some other stuff ...
    return@runBlocking res
}

And these are the outputs for two different executions:

Output 1
0: started
1: started
2: started
3: started
4: started
5: started
6: started
7: started
8: started
9: started
10: started
3: finished
2: finished
0: finished
4: finished
8: finished
6: finished
10: finished
7: finished
1: finished
9: finished
5: finished
Output 2
0: started
1: started
2: started
3: started
4: started
5: started
6: started
7: started
8: started
9: started
10: started
9: finished
6: finished
1: finished
0: finished
4: finished
8: finished
7: finished
2: finished
3: finished
5: finished
10: finished

So your code works as you expected, I don’t know why it doesn’t work for you. Try testing the code I posted above.


#3

I think the result depends on whether the “execution that takes random time” suspends or not. Compare delay vs Thread.sleep. (I can’t test it myself at the moment.)


#4

Yes, you are right. If you use Thread.sleep then the output is as you say.


#5

Actually the operations I’m performing is I/O bound. I guess it’s actually blocking the thread. Should I be using threads instead then?


#6

runBlocking use the current thread and an event loop, please consider the official documentation https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-core/kotlinx.coroutines/run-blocking.html

And please consider https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-core/kotlinx.coroutines/await-all.html


#7

If you specify the coroutine context then the code runs as expected:

import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.async
import kotlinx.coroutines.runBlocking
import kotlin.random.Random

fun main() = initialize {
    val jobs = List(10) {
        async(Dispatchers.Default) {
            println("$it: started")
            Thread.sleep(Random.nextLong(100, 1000))
            println("$it: finished")
        }
    }
    jobs.forEach { it.await() }
    return@initialize
}

fun <T> initialize(block: suspend CoroutineScope.() -> T) = runBlocking {
    // ... some stuff ...
    val res: T = block()
    // ... some other stuff ...
    return@runBlocking res
}
Output
0: started
1: started
2: started
3: started
4: started
5: started
6: started
7: started
1: finished
8: started
8: finished
9: started
5: finished
2: finished
0: finished
7: finished
6: finished
3: finished
4: finished
9: finished

Note: I have an 8 thread processor that’s why only 0-7 start and then wait for a thread to be free (1: finished) to then start another one (8: started), and so on.

Check https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-core/kotlinx.coroutines/-dispatchers/index.html to decide with one is the best dispatcher for your use case.


#8

That was it! Using the IO dispatcher I managed to actually achieve concurrency! Thank you guys :slight_smile:

Unfortunately the SDK I’m using has restrictions on multithreading so I’ll have to figure out how to handle things properly.