How to measure execution time of an aync query/request inside Kotlin coroutines

Support
1

I have a microservice on which I am using Kotlin coroutines to perform a bunch of db queries asynchronously, and I want to monitor the execution time for each one of those queries for potential performance optimization.

The implementation I have is like this:

val requestSemaphore = Semaphore(5)
val baseProductsNos = productRepository.getAllBaseProductsNos()
runBlocking {
    baseProductsNos
        .chunked(500)
        .map { batchOfProductNos ->
            launch {
                requestSemaphore.withPermit {
                    val rawBaseProducts = async {
                        productRepository.getBaseProducts(batchOfProductNos)
                    }

                    val mediaCall = async {
                        productRepository.getProductMedia(batchOfProductNos)
                    }

                    val productDimensions = async {
                        productRepository.getProductDimensions(batchOfProductNos)
                    }

                    val allowedCountries = async {
                        productRepository.getProductNosInCountries(batchOfProductNos, countriesList)
                    }

                    val variants = async {
                        productRepository.getProductVariants(batchOfProductNos)
                    }

                    //some irrelevant processing of the results
                }
            }
        }.joinAll()
}

As you can see I use Semaphore to limit the number of parallel jobs, and all the repository methods are suspendable and those are the ones I want to measure the execution time for. Here is an example of an implementation inside ProductRepository:

  suspend fun getBaseProducts(baseProductNos: List<String>): List<RawBaseProduct> =
    withContext(Dispatchers.IO) {
      namedParameterJdbcTemplateMercator.query(
        getSqlFromResource(baseProductSql),
        getNamedParametersForBaseProductNos(baseProductNos),
        RawBaseProductRowMapper()
      )
    }

And to do that I tried this :

      val rawBaseProductsCall = async {
        val startTime = System.currentTimeMillis()

        val result = productRepository.getBaseProducts(productNos)

        val endTime = System.currentTimeMillis()
        logger.info("${TemporaryLog("call-duration", "rawBaseProductsCall", endTime - startTime)}")

        result
      }

But this measurement always returns inconsistent results for the average in contrast to the sequential implementation(without coroutines), and the only explanation I can come up with is that this measurement includes the suspension time, and obviously I am only interested in the time that the queries take to execute without a suspension time if there was any.

I don’t know if what I am trying to do is possible in Kotlin, but it looks like python supports this. So I will appreciate any help to do something similar in Kotlin.