withTimeoutOrNull returns null even when it did not timeout itself

[elizarov]

Copied from message by @gregschlom at public slack:

Hey guys. I have an issue with nested withTimeouts. Here’s some example code:

    val channel = Channel<Int>()

    // this blocks indefinitely if the channel is empty
    suspend fun nexValue(): Int {
        println("Waiting for next value ")
        return channel.receive()
    }

    // same as nextValue(), but returns null after the timeout expires
    suspend fun nextValueWithTimout(t: Long): Int? {
        return withTimeoutOrNull(t) { nexValue() }
    }

    suspend fun longOperation() {
        println("Starting long operation")
        while (true) {
            val v = nextValueWithTimout(1000)
            if (v == null) {
                println("timed out")
                // Nothing was received in our channel.
                // Do some other work while we wait for the value to arrive. Maybe we want to re-try sending
                // a message to our value producer for example
            }
            if (v == 42) return
        }
    }

    @Test
    fun main() = runBlocking {
        // This never returns. Instead we get stuck in an infinite loop in the while() above
        withTimeout(5000) {
            longOperation()
        }
    }

The problem here is that we have two nested withTimeout calls

The code is generally suspended inside nextValue(). When the outer timeout fires (the one in the main function), there’s no way for the code in nextValueWithTimout to know whether it was it’s own timeout that fired or some other timeout

Therefore it returns null either way

[gregschlom]

Modifiying nextValueWithTimout like so:

    suspend fun nextValueWithTimout(t: Long): Int? {
        val result = withTimeoutOrNull(t) { nexValue() }
        yield()
        return result 
    }

Fixes the issue for me, but I’m not sure I fully understand the semantics of yield. Is this logically correct? I’m worried that the call to yield() might suspend my coroutine for an undetermined amount of time.

[elizarov]

Yield just reschedules the task and checks for cancellation. That is why your particular problem is fixed. It does not address the core issue itself. The root questions here is what semantics should withTimeoutOrNull have when some other withTimeout invocation (either inside or outside of it) times out.

[elizarov]

I'm personally inclined to rule that withTimeoutOrNull shall return null only if its own timeout is exceeded and change its implementation accordingly.

[gregschlom]

And same goes for withTimeout, right? Should return null only if its own timeout fires.

[elizarov]

There is no problem with withTimeout. It throws an exception on timeout and always rethrows an inner exception if any. It cannot/should not consume or alter inner exception in any way, so withTimeout does not provide any way to distinguish which timeout had fired and it has to stay this way.

[gregschlom]

I see. I originally encountered this problem because I wasn't aware of withTimeoutOrNull (it looks like it's a recent addition) and was doing things this way:

suspend fun nextValueWithTimout(t: Long): Int? {
    try {
        return withTimeout(t) { nexValue() }
    catch (e: CancellationException) {
        return null
    }
}

I understand they might be different use cases, but from a user point of view this way of doing things also looks pretty innocent at first. Hard to see that you're shooting yourself in the foot here.

I wonder if there's a way to make it harder for users to do stupid things like this.

[nkiesel]

Another test program. I'm surprised that both nested1 and nested2 print the same value for all permutations. Why is nested2(1, 2, 3) not returning "outer timeout"?

import kotlinx.coroutines.experimental.*
import java.util.concurrent.TimeUnit

val S = TimeUnit.SECONDS

suspend fun <T> withTimeoutOrNull2(time: Long, unit: TimeUnit, block: suspend () -> T): T? = try {
    withTimeout(time, unit) {
        block()
    }
} catch (_: CancellationException) { null }

suspend fun nested1(outer: Long, inner: Long, delayed: Long) =
        withTimeoutOrNull(outer, S) {
            withTimeoutOrNull(inner, S) {
                delay(delayed, S)
                "delay"
            } ?: "inner timeout"
        } ?: "outer timeout"

suspend fun nested2(outer: Long, inner: Long, delayed: Long) =
        withTimeoutOrNull2(outer, S) {
            withTimeoutOrNull2(inner, S) {
                delay(delayed, S)
                "delay"
            } ?: "inner timeout"
        } ?: "outer timeout"

suspend fun test(outer: Long, inner: Long, delayed: Long) {
    val result1 = nested1(outer, inner, delayed)
    val result2 = nested2(outer, inner, delayed)
    println("test($outer, $inner, $delayed) = { 1: $result1, 2: $result2 }")
}

fun main(args: Array<String>) = runBlocking {
    test(1, 2, 3)
    test(1, 3, 2)
    test(2, 1, 3)
    test(2, 3, 1)
    test(3, 1, 2)
    test(3, 2, 1)
}

[gregschlom]

@nkiesel

Why is nested2(1, 2, 3) not returning "outer timeout"?

• The outer timeout fires at 1 second, and makes delay(3) resume with a CancellationException
• The inner withTimeoutOrNull catches the exception, concludes that it timed out, returns null which gets converted to the string "inner timeout"
• The block in outer timeout completes with a valid value ("inner timeout"), has no idea it actually timed out because the CancellationException was swallowed by the inner withTimeoutOrNull

For the other cases:

• test(1, 3, 2) is identical to test(1, 2, 3) - outer times out while suspended in the delay()
• test(2, 1, 3): inner times out first so you get "inner timeout" as expected (ie: behavior is correct)
• test(2, 3, 1): delay is lower than time outs, so you get the correct behavior
• test(3, 1, 2): inner times out first, so you get the correct behavior
• test(3, 2, 1): delay is lower than time outs, so you get the correct behavior

For reference, the output of the test above is:

test(1, 2, 3) = { 1: inner timeout, 2: inner timeout }
test(1, 3, 2) = { 1: inner timeout, 2: inner timeout }
test(2, 1, 3) = { 1: inner timeout, 2: inner timeout }
test(2, 3, 1) = { 1: delay, 2: delay }
test(3, 1, 2) = { 1: inner timeout, 2: inner timeout }
test(3, 2, 1) = { 1: delay, 2: delay }

[gregschlom]

FYI, here's my workaround to the problem:

    /**
     * Throws if the current coroutine is completed or cancelled
     */
    suspend fun checkStillActive() {
        suspendCoroutine<Unit> { cont ->
            val job = cont.context[Job]
            if (job?.isCompleted == true) throw job.getCompletionException()
            cont.resume(Unit)
        }
    }

The call checkStillActive() after each call to withTimeout[OrNull], like so:

    suspend fun nested1(outer: Long, inner: Long, delayed: Long) =
            withTimeoutOrNull(outer, S) {
                val result = withTimeoutOrNull(inner, S) {
                    delay(delayed, S)
                    "delay"
                } ?: "inner timeout"
                checkStillActive()  // <---- here
                result
            } ?: "outer timeout"

And:

    suspend fun <T> withTimeoutOrNull2(time: Long, unit: TimeUnit, block: suspend () -> T): T? = try {
        withTimeout(time, unit) {
            block()
        }
    } catch (_: CancellationException) {
        checkStillActive()  // <---- here
        null
    }

This gives the correct results:

test(1, 2, 3) = { 1: outer timeout, 2: outer timeout }
test(1, 3, 2) = { 1: outer timeout, 2: outer timeout }
test(2, 1, 3) = { 1: inner timeout, 2: inner timeout }
test(2, 3, 1) = { 1: delay, 2: delay }
test(3, 1, 2) = { 1: inner timeout, 2: inner timeout }
test(3, 2, 1) = { 1: delay, 2: delay }

[elizarov]

Fixed in develop branch