IssueTracker

Hello there!

Thank you for the heads up this has been already reported internally.

Hello,

The expected impact of this bug is considered low (it's a narrow edge case with no upvotes, and should be avoidable on the consumer side by trimming inputs). As a result, our engineering team has deprioritized the issue until there is evidence of further impact. I am going to mark this as Won't Fix to more accurately reflect this. Please re-open if the scope of the issue changes. Thanks!

Taking a bit deeper look, and it seems like interpreter does something weird there.

If I print dispatched tasks here, I get a println in a normal case. When live edit is involved, the continuation context has correct AndroidUiDispatcher, but nothing is scheduled on that dispatcher.

If I print dispatched tasks here, I get a println in a normal case. When live edit is involved, the continuation context has correct AndroidUiDispatcher, but nothing is scheduled on that dispatcher.

Can you be more specific? Normally we shouldn't be interpreting the androidx libraries (unless you loaded the sources code and started modifying it in your project).

The only thing we would be interpeting would be the modified .kt files in the project. It is also a Java bytecode based interpeter so it is not "aware" of coroutine and context.

I don't think AndroidUiDispatcher itself is interpreted, but it looks like a mistake in bytecode that leads to dispatching the task.

Slightly concerning, but the coroutine is in Cancelling state in the crash trace (StandaloneCoroutine{Cancelling}@fdc3c20)

Nvm, it is because of exception being thrown.

I don't think AndroidUiDispatcher itself is interpreted, but it looks like a mistake in bytecode that leads to dispatching the task.

I think Andrei might be onto something. It might be the interpeter is doing something wrong.

I have been trying to narrow this down. Let say we have one file with just one funtion Launch()

@Composable
fun Launch() {
    val scope = rememberCoroutineScope()
    Log.d("DEBUG", "     Launch1   " + scope);

    SideEffect {
        scope.launch {
            withContext(Dispatchers.IO) {
                Log.d("DEBUG", ">>> Should be DefaultDispatcher-worker: ${Thread.currentThread().name}")
            }
            
            Log.d("DEBUG", ">>> Should be main: ${Thread.currentThread().name}")
        }
    }
}

If we only interpet this function, we ended up with Should be main: DefaultDispatcher-worker-3. Note calling uninterpeted version of Launch() from an interpeted class is fine.

However, the following two versions are fine:

@Composable
fun Launch() {
    val scope = rememberCoroutineScope()
    Log.d("DEBUG", "     Launch1   " + scope);

    SideEffect {
        scope.launch {
            Log.d("DEBUG", ">>> Should be main: ${Thread.currentThread().name}")

            withContext(Dispatchers.IO) {
                Log.d("DEBUG", ">>> Should be DefaultDispatcher-worker: ${Thread.currentThread().name}")
            }
            
        }
    }
}

and

@Composable
fun Launch() {
    val scope = rememberCoroutineScope()
    Log.d("DEBUG", "     Launch1   " + scope);

    SideEffect {
        scope.launch {
            Log.d("DEBUG", ">>> Should be main: ${Thread.currentThread().name}")
        }
    }
}

You can actually take away the Compose code. This identical block also cause the issue:

@Composable
fun Launch(s : String) {
    runBlocking {

        withContext(Dispatchers.IO) {
            Log.d("DEBUG", ">>> Should be DefaultDispatcher-worker: ${Thread.currentThread().name}")
        }

        Log.d("DEBUG", ">>>>    Should be main: ${Thread.currentThread().name} ")
        
    }
}

I can see Fix226201991Eval in the stacktrace which is was our "artisanal" desugaring (and removed in March 2023). But @acleung seems to be able to reproduce the issue on HEAD?

re: #10

Yes, I don't think this is related to the Fix226201991Eval. I was able to reproduce it witwh studio-main using the code from #9. It seems the 2nd block is being set up with the wrong dispatcher.

By second block, you mean withContext?

By second block, you mean withContext?

I meant Log.d("DEBUG", ">>>> Should be main: ${Thread.currentThread().name} ")

The interpeter will invoke that on the dispatcher thread instead.

Alright, I dug a bit deeper.

The compiled bytecode looks correct coming out of the Live Edit Kotlin compiler invocation. I didn't see major differences.

I also don't see anything in the interpreter neither. It appears to be doing what it is intented. I also added a unit test for it. runBlocking starts everything with the default context. The withContext() calls also starts with the right Dispatcher IO context.

What I suspect had gone wrong is what happens after the withContext() lambda returns. From what I understand so far, suspend functions store the state of the execution in a Continuation object which remembers both the location and the Dispatcher information and that might be wrong somehow.

When I execute this code:

class ContextBug {
    companion object {
        @JvmStatic
        fun Launch() {
            runBlocking() {
                Log.d("DEBUG", ">>>> Should be main: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
                withContext(Dispatchers.IO) {
                    Log.d("DEBUG", ">>> Should be DefaultDispatcher-worker: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
                }
                Log.d("DEBUG", ">>>> Should be main: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
            }
        }
    }
}

We get the following normally:

2024-01-24 22:35:38.983  5897-5897  DEBUG                   com.example.myapplication            D  >>>> Should be main: main having context: [BlockingCoroutine{Active}@24fa393, BlockingEventLoop@6719fd0]
2024-01-24 22:35:38.985  5897-5919  DEBUG                   com.example.myapplication            D  >>> Should be DefaultDispatcher-worker: DefaultDispatcher-worker-1 having context: [DispatchedCoroutine{Active}@7f29bc9, Dispatchers.IO]
2024-01-24 22:35:38.986  5897-5897  DEBUG                   com.example.myapplication            D  >>>> Should be main: main having context: [BlockingCoroutine{Active}@24fa393, BlockingEventLoop@6719fd0]

2024-01-24 22:35:02.438  5663-5663  DEBUG                   com.example.myapplication            D  >>>> Should be main: main having context: [BlockingCoroutine{Active}@d07c13e, BlockingEventLoop@d225b9f]
2024-01-24 22:35:02.450  5663-5691  DEBUG                   com.example.myapplication            D  >>> Should be DefaultDispatcher-worker: DefaultDispatcher-worker-1 having context: [DispatchedCoroutine{Active}@b85a4ec, Dispatchers.IO]
2024-01-24 22:35:02.457  5663-5691  DEBUG                   com.example.myapplication            D  >>>> Should be main: DefaultDispatcher-worker-1 having context: [BlockingCoroutine{Active}@d07c13e, BlockingEventLoop@d225b9f]

The context looks right (at least from the toString()) but the thread is wrong.

It sounds like this might be a coroutine bug or at least one that can't be understood without understanding corountine internals. I am going to file a bug there.

I opened https://github.com/Kotlin/kotlinx.coroutines/issues/4022

Summary from the JB bug / Tolstopyatov's replies

If we have this example.

runBlocking() {
    Log.d("DEBUG", ">>>> F")
    Log.d("DEBUG", ">>>> Should be main: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
    suspendCoroutineUninterceptedOrReturn<Unit> {
        Log.d("DEBUG", ">>> Proxy: ${it.intercepted()}")
        Unit
    }
    withContext(Executors.newCachedThreadPool().asCoroutineDispatcher()) {
        Log.d("DEBUG", ">>> Should be DefaultDispatcher-worker: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
    }
    Log.d("DEBUG", ">>>> Should be main: ${Thread.currentThread().name} having context: ${currentCoroutineContext()}")
}

This is the output after Live Edit

>>> Proxy: com.android.tools.deploy.liveedit.ProxyClassHandler@8bd34b3

What this mean is that the method handler object we created for the lambda somehow escaped into the user's code. I can't really think of a path where this can happen.

I am going to assign this to Noah since he implemented most of the proxy object code.

After looking at this for a bit, nothing has escaped; toString for a proxy object prints the name of the handler, not the actual proxy itself (because the method invocation is forwarded to the handler, which runs its own toString). I'll add some better logging to make this more clear.

For the actual issue, this is gonna be a difficult one; based on the github issue, we're going to need a pretty solid understanding of the internals of coroutines and the types they expect to receive.

I am catching the Compose runtime bug with the same pattern:

									val state = remember { mutableIntStateOf(0) }
									LaunchedEffect(Unit) {
										Log.d("xoxoxo", " 1 xoxoxo Test: thread: ${Thread.currentThread().name}")
										withContext(Dispatchers.IO) {
											Log.d("xoxoxo", " 12 xoxoxo Test: thread: ${Thread.currentThread().name}")
											delay(0)
										}
										Log.d("xoxoxo", " 2 xoxoxo Test: thread: ${Thread.currentThread().name}")
										state.intValue = 1
									}

When setting state.intValue = 1 after returning from withContext, in some cases the thread is not that was before jumping into withContext. And compose runtime crashes with exception java.lang.IllegalStateException: Reading a state that was created after the snapshot was taken or in a snapshot that has not yet been applied (song with exception trace - https://suno.com/song/6a3f5a32-085f-4f3f-af57-eae0ca8af330)

This happens without liveedit at all, at our testing stand in debug build.

Reading a state that was created after the snapshot was taken or in a snapshot that has not yet been applied

This does not sound like the same Live Edit bug we are seeing here. Can you open another bug for the Compose team to take a look instead?

It is the same cause in this case since the state update might race with composition from a different thread.

It is the same cause in this case since the state update might race with composition from a different thread.

I am not 100% sure, Andrei.

From what we discovered, Live Edit updated one of the Corountine state object with a different class hierarchy that caused the dispatcher to fall back on dispatching the main thread when Live Edit happened.

At least for the project attached in #1, Noah has a fix for it when Live Edit is involved.

I would like to add to #18, this is not reproduced on a simple debug run, but on instrumentation test with build type 'debug' and UIAutomator. I am not able to make I trivial reproduceable project yet.

re: #22.

There is definitely something else here that isn't rooted from Live Edit despite similar behavior.

I'd suggest opening another bug with possible reproduce step so the compose team can take a look.

We should keep this bug focus on Live Edit specific cause.