Issue

Remember that: coroutineScope: waits for all its children before it can finish itself (when children do not throw)

This creates 2 potential gotchas IF we mix essential and non essential calls:

  • Essential data could be slowed down due to waiting for non essential function to finish.
  • Essential data can be blocked from returning if non essential data fails.

Example: slow down

Here is an example where after get the required data we spawn a launch to notify metrics. We do it in the same scope and hence, we end up delaying data being shown to the user until we notify metrics.

GT-Sandbox-Snapshot

Code

package com.glassthought.sandbox

import com.glassthought.sandbox.util.out.impl.out
import gt.sandbox.util.output.Emojis
import gt.sandbox.util.output.Out
import kotlinx.coroutines.CoroutineName
import kotlinx.coroutines.async
import kotlinx.coroutines.coroutineScope
import kotlinx.coroutines.launch
import kotlinx.coroutines.runBlocking
import kotlin.system.exitProcess
import kotlin.time.Duration.Companion.milliseconds

private suspend fun mainImpl(out: Out) {
  val useCase = GetUserDataUseCase(UserDataRepository())

  val userData = useCase.getUserData()

  out.info(
    "User data that can be used by user: $userData"
  )
}

class GetUserDataUseCase(
  private val repo: UserDataRepository,
) {
  suspend fun getUserData() = coroutineScope {
    val name = async(CoroutineName("getName()")) { repo.getName() }
    val friends = async(CoroutineName("getFriends()")) { repo.getFriends() }
    val profile = async(CoroutineName("getProfile()")) { repo.getProfile() }

    // Await to get all the user data - ESSENTIAL call!
    val user = User(
      name = name.await(),
      friends = friends.await(),
      profile = profile.await()
    )

    out.info("We have all the required user data, let's just notify metrics...")

    // Notify metric system that we got the user data.
    // NON-ESSENTIAL call.
    //   - 1) we end up blocking prior to returning essential user data.
    //   - 2) if notifyMetricsOfUserDataLoaded() fails the USER data will NOT be returned.
    launch(CoroutineName("notifyMetricsOfUserDataLoaded()")) { repo.notifyMetricsOfUserDataLoaded() }

    user
  }
}


fun main(): Unit = runBlocking {
  out.info("START - ON MAIN")

  try {
    mainImpl(out)
  } catch (e: Exception) {
    out.error("EXCEPTION AT MAIN! [${e::class.simpleName}] with msg=[${e.message}]!")
    exitProcess(1)
  }

  out.info("DONE - WITHOUT errors on MAIN")
}

class UserDataRepository {
  suspend fun getName(): String {

    return out.actionWithMsg(
      "getName()", { "Tom" }, 500.milliseconds
    )
  }

  suspend fun getFriends() {
    return out.actionWithMsg(
      "getFriends()", { listOf("Alice", "Bob") }, 1000.milliseconds
    )
  }

  suspend fun getProfile() {

    return out.actionWithMsg(
      "getProfile()", { "Profile of Tom" }, 1500.milliseconds
    )
  }

  suspend fun notifyMetricsOfUserDataLoaded() {
    return out.actionWithMsg(
      "${Emojis.TURTLE}notifyMetricsOfUserDataLoaded()${Emojis.TURTLE}", { "metrics-updated" }, 5000.milliseconds
    )
  }
}


class User(name: String, friends: Any, profile: Any)

Command to reproduce:

gt.sandbox.checkout.commit 9771a4493454f0700e2d \
&& cd "${GT_SANDBOX_REPO}" \
&& cmd.run.announce "./gradlew run --quiet"

Recorded output of command:

Picked up JAVA_TOOL_OPTIONS: -Dkotlinx.coroutines.debug
Picked up JAVA_TOOL_OPTIONS: -Dkotlinx.coroutines.debug
[INFO][elapsed:   14ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] START - ON MAIN
[INFO][elapsed:   35ms][🥇][⓶][coroutname:@getName()#2][tname:main/tid:1] [>] Starting action=[getName()] with delay before action of [500 ms]
[INFO][elapsed:   37ms][🥇][⓷][coroutname:@getFriends()#3][tname:main/tid:1] [>] Starting action=[getFriends()] with delay before action of [1000 ms]
[INFO][elapsed:   37ms][🥇][⓸][coroutname:@getProfile()#4][tname:main/tid:1] [>] Starting action=[getProfile()] with delay before action of [1500 ms]
[INFO][elapsed:  537ms][🥇][⓶][coroutname:@getName()#2][tname:main/tid:1] [<] Finished action=[getName()].
[INFO][elapsed: 1037ms][🥇][⓷][coroutname:@getFriends()#3][tname:main/tid:1] [<] Finished action=[getFriends()].
[INFO][elapsed: 1537ms][🥇][⓸][coroutname:@getProfile()#4][tname:main/tid:1] [<] Finished action=[getProfile()].
[INFO][elapsed: 1538ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] We have all the required user data, let's just notify metrics...
[INFO][elapsed: 1539ms][🥇][⓹][coroutname:@notifyMetricsOfUserDataLoaded()#5][tname:main/tid:1] [>] Starting action=[🐢notifyMetricsOfUserDataLoaded()🐢] with delay before action of [5000 ms]
[INFO][elapsed: 6539ms][🥇][⓹][coroutname:@notifyMetricsOfUserDataLoaded()#5][tname:main/tid:1] [<] Finished action=[🐢notifyMetricsOfUserDataLoaded()🐢].
[INFO][elapsed: 6540ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] User data that can be used by user: com.glassthought.sandbox.User@34b7bfc0
[INFO][elapsed: 6540ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] DONE - WITHOUT errors on MAIN

Example: non essential call preventing Essential

Now let's take the same example but instead of just delaying the metric notification first delays and then throws an exception.

Now not only did we make the user wait, they waited for a crash and never saw their data:

GT-Sandbox-Snapshot

Code

package com.glassthought.sandbox

import com.glassthought.sandbox.util.out.impl.out
import gt.sandbox.util.output.Emojis
import gt.sandbox.util.output.Out
import kotlinx.coroutines.CoroutineName
import kotlinx.coroutines.async
import kotlinx.coroutines.coroutineScope
import kotlinx.coroutines.launch
import kotlinx.coroutines.runBlocking
import kotlin.system.exitProcess
import kotlin.time.Duration.Companion.milliseconds

private suspend fun mainImpl(out: Out) {
  val useCase = GetUserDataUseCase(UserDataRepository())

  val userData = useCase.getUserData()

  out.info(
    "User data that can be used by user: $userData"
  )
}

class GetUserDataUseCase(
  private val repo: UserDataRepository,
) {
  suspend fun getUserData() = coroutineScope {
    val name = async(CoroutineName("getName()")) { repo.getName() }
    val friends = async(CoroutineName("getFriends()")) { repo.getFriends() }
    val profile = async(CoroutineName("getProfile()")) { repo.getProfile() }

    // Await to get all the user data - ESSENTIAL call!
    val user = User(
      name = name.await(),
      friends = friends.await(),
      profile = profile.await()
    )

    out.info("We have all the required user data, let's just notify metrics...")

    // Notify metric system that we got the user data.
    // NON-ESSENTIAL call.
    //   - 1) we end up blocking prior to returning essential user data.
    //   - 2) if notifyMetricsOfUserDataLoaded() fails the USER data will NOT be returned.
    launch(CoroutineName("notifyMetricsOfUserDataLoaded()")) { repo.notifyMetricsOfUserDataLoaded() }

    user
  }
}


fun main(): Unit = runBlocking {
  out.info("START - ON MAIN")

  try {
    mainImpl(out)
  } catch (e: Exception) {
    out.error("EXCEPTION AT MAIN! [${e::class.simpleName}] with msg=[${e.message}]!")
    exitProcess(1)
  }

  out.info("DONE - WITHOUT errors on MAIN")
}

class UserDataRepository {
  suspend fun getName(): String {

    return out.actionWithMsg(
      "getName()", { "Tom" }, 500.milliseconds
    )
  }

  suspend fun getFriends() {
    return out.actionWithMsg(
      "getFriends()", { listOf("Alice", "Bob") }, 1000.milliseconds
    )
  }

  suspend fun getProfile() {

    return out.actionWithMsg(
      "getProfile()", { "Profile of Tom" }, 1500.milliseconds
    )
  }

  suspend fun notifyMetricsOfUserDataLoaded() {
    return out.actionWithMsg(
      "${Emojis.TURTLE}notifyMetricsOfUserDataLoaded()${Emojis.TURTLE}", {

        throw MyRuntimeException.create(
          "metric-system-is-down",
          out
        )
      }, 5000.milliseconds
    )
  }
}


class User(name: String, friends: Any, profile: Any)

Command to reproduce:

gt.sandbox.checkout.commit e74dc0d38ef9f00c9457 \
&& cd "${GT_SANDBOX_REPO}" \
&& cmd.run.announce "./gradlew run --quiet"

Recorded output of command:

Picked up JAVA_TOOL_OPTIONS: -Dkotlinx.coroutines.debug
Picked up JAVA_TOOL_OPTIONS: -Dkotlinx.coroutines.debug
[INFO][elapsed:   20ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] START - ON MAIN
[INFO][elapsed:   47ms][🥇][⓶][coroutname:@getName()#2][tname:main/tid:1] [>] Starting action=[getName()] with delay before action of [500 ms]
[INFO][elapsed:   48ms][🥇][⓷][coroutname:@getFriends()#3][tname:main/tid:1] [>] Starting action=[getFriends()] with delay before action of [1000 ms]
[INFO][elapsed:   49ms][🥇][⓸][coroutname:@getProfile()#4][tname:main/tid:1] [>] Starting action=[getProfile()] with delay before action of [1500 ms]
[INFO][elapsed:  549ms][🥇][⓶][coroutname:@getName()#2][tname:main/tid:1] [<] Finished action=[getName()].
[INFO][elapsed: 1049ms][🥇][⓷][coroutname:@getFriends()#3][tname:main/tid:1] [<] Finished action=[getFriends()].
[INFO][elapsed: 1549ms][🥇][⓸][coroutname:@getProfile()#4][tname:main/tid:1] [<] Finished action=[getProfile()].
[INFO][elapsed: 1550ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] We have all the required user data, let's just notify metrics...
[INFO][elapsed: 1551ms][🥇][⓹][coroutname:@notifyMetricsOfUserDataLoaded()#5][tname:main/tid:1] [>] Starting action=[🐢notifyMetricsOfUserDataLoaded()🐢] with delay before action of [5000 ms]
[WARN][elapsed: 6582ms][🥇][⓹][coroutname:@notifyMetricsOfUserDataLoaded()#5][tname:main/tid:1]    💥 throwing exception=[MyRuntimeException] with msg=[metric-system-is-down]
[WARN][elapsed: 6582ms][🥇][⓹][coroutname:@notifyMetricsOfUserDataLoaded()#5][tname:main/tid:1] [<][💥] Finished action=[🐢notifyMetricsOfUserDataLoaded()🐢], threw exception of type=[MyRuntimeException].
[ERROR][elapsed: 6587ms][🥇][①][coroutname:@coroutine#1][tname:main/tid:1] EXCEPTION AT MAIN! [MyRuntimeException] with msg=[metric-system-is-down]!

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':app:run'.
> Process 'command '/home/nickolaykondratyev/.jdks/corretto-21.0.7/bin/java'' finished with non-zero exit value 1

* Try:
> Run with --stacktrace option to get the stack trace.
> Run with --info or --debug option to get more log output.
> Run with --scan to get full insights.
> Get more help at https://help.gradle.org.

BUILD FAILED in 7s

Backlinks