Part n in my quest for hunting down all the :snowf...
# compose
v
Part n in my quest for hunting down all the ❄️ flaky tests... can I get a sanity check on this? I thought
LaunchedEffect
would always run on the main thread?
I have a
LauncedEffect
calling navigate like this:
Copy code
LaunchedEffect(key, ...) { navController.navigate(...) { popUpTo(...) } }
And very rarely when running instrumented tests, I get this exception. Am I missing something? Full stack trace in thread.
Copy code
java.lang.IllegalStateException: Method setCurrentState must be called on the main thread
Copy code
java.lang.IllegalStateException: Method setCurrentState must be called on the main thread
at androidx.lifecycle.LifecycleRegistry.enforceMainThreadIfNeeded(LifecycleRegistry.kt:296)
at androidx.lifecycle.LifecycleRegistry.setCurrentState(LifecycleRegistry.kt:105)
at androidx.navigation.NavBackStackEntry.updateState(NavBackStackEntry.kt:188)
at androidx.navigation.NavBackStackEntry.setMaxLifecycle(NavBackStackEntry.kt:159)
at androidx.navigation.NavController.popEntryFromBackStack(NavController.kt:761)
at androidx.navigation.NavController.access$popEntryFromBackStack(NavController.kt:68)
at androidx.navigation.NavController$executePopOperations$1.invoke(NavController.kt:643)
at androidx.navigation.NavController$executePopOperations$1.invoke(NavController.kt:640)
at androidx.navigation.NavController$NavControllerNavigatorState.pop(NavController.kt:330)
at androidx.navigation.NavigatorState.popWithTransition(NavigatorState.kt:149)
at androidx.navigation.NavController$NavControllerNavigatorState.popWithTransition(NavController.kt:343)
at androidx.navigation.compose.ComposeNavigator.popBackStack(ComposeNavigator.kt:67)
at androidx.navigation.NavController.popBackStackInternal(NavController.kt:280)
at androidx.navigation.NavController.executePopOperations(NavController.kt:640)
at androidx.navigation.NavController.popBackStackInternal(NavController.kt:627)
at androidx.navigation.NavController.navigate(NavController.kt:1837)
at androidx.navigation.NavController.navigate(NavController.kt:1812)
at androidx.navigation.NavController.navigate(NavController.kt:2220)
at androidx.navigation.NavController.navigate$default(NavController.kt:2215)
at androidx.navigation.NavController.navigate(NavController.kt:2200)
at <mypackage>(:19) <- helper functions
at <mypackage>(:17) <- helper functions
at <mypackage>.invokeSuspend(:266) <- in a LaunchedEffect
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at androidx.compose.ui.test.ApplyingContinuationInterceptor$SendApplyContinuation.resumeWith(ApplyingContinuationInterceptor.kt:65)
at androidx.compose.ui.test.FrameDeferringContinuationInterceptor$TrampolinedTask.resume(FrameDeferringContinuationInterceptor.kt:137)
at androidx.compose.ui.test.FrameDeferringContinuationInterceptor.runWithoutResumingCoroutines(FrameDeferringContinuationInterceptor.kt:75)
at androidx.compose.ui.test.TestMonotonicFrameClock.performFrame(TestMonotonicFrameClock.jvm.kt:132)
at androidx.compose.ui.test.TestMonotonicFrameClock.access$performFrame(TestMonotonicFrameClock.jvm.kt:53)
at androidx.compose.ui.test.TestMonotonicFrameClock$withFrameNanos$2$1$2.invokeSuspend(TestMonotonicFrameClock.jvm.kt:110)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:367)
at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:30)
at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:25)
at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:110)
at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:126)
at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:56)
at kotlinx.coroutines.BuildersKt.launch(Unknown Source:1)
at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:47)
at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source:1)
at androidx.compose.ui.test.TestMonotonicFrameClock.withFrameNanos(TestMonotonicFrameClock.jvm.kt:108)
at androidx.compose.runtime.Recomposer$runRecomposeAndApplyChanges$2.invokeSuspend(Recomposer.kt:548)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at androidx.compose.ui.test.ApplyingContinuationInterceptor$SendApplyContinuation.resumeWith(ApplyingContinuationInterceptor.kt:65)
at androidx.compose.ui.test.FrameDeferringContinuationInterceptor$FrameDeferredContinuation.resumeWith(FrameDeferringContinuationInterceptor.kt:194)
at kotlinx.coroutines.DispatchedTaskKt.resume(DispatchedTask.kt:179)
at kotlinx.coroutines.DispatchedTaskKt.dispatch(DispatchedTask.kt:168)
at kotlinx.coroutines.CancellableContinuationImpl.dispatchResume(CancellableContinuationImpl.kt:474)
at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl(CancellableContinuationImpl.kt:508)
at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl$default(CancellableContinuationImpl.kt:497)
at kotlinx.coroutines.CancellableContinuationImpl.resumeWith(CancellableContinuationImpl.kt:368)
at androidx.compose.runtime.Recomposer$recompositionRunner$2$unregisterApplyObserver$1.invoke(Recomposer.kt:979)
at androidx.compose.runtime.Recomposer$recompositionRunner$2$unregisterApplyObserver$1.invoke(Recomposer.kt:973)
at androidx.compose.runtime.snapshots.SnapshotKt.advanceGlobalSnapshot(Snapshot.kt:1815)
at androidx.compose.runtime.snapshots.SnapshotKt.advanceGlobalSnapshot(Snapshot.kt:1830)
at androidx.compose.runtime.snapshots.SnapshotKt.access$advanceGlobalSnapshot(Snapshot.kt:1)
at androidx.compose.runtime.snapshots.Snapshot$Companion.sendApplyNotifications(Snapshot.kt:583)
at androidx.compose.ui.test.ApplyingContinuationInterceptor$SendApplyContinuation.resumeWith(ApplyingContinuationInterceptor.kt:66)
at androidx.compose.ui.test.FrameDeferringContinuationInterceptor$FrameDeferredContinuation.resumeWith(FrameDeferringContinuationInterceptor.kt:194)
at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:283)
at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith$default(DispatchedContinuation.kt:278)
at kotlinx.coroutines.internal.ScopeCoroutine.afterCompletion(Scopes.kt:27)
at kotlinx.coroutines.JobSupport.continueCompleting(JobSupport.kt:940)
at kotlinx.coroutines.JobSupport.access$continueCompleting(JobSupport.kt:25)
at kotlinx.coroutines.JobSupport$ChildCompletion.invoke(JobSupport.kt:1159)
at kotlinx.coroutines.JobSupport.notifyCompletion(JobSupport.kt:1497)
at kotlinx.coroutines.JobSupport.completeStateFinalization(JobSupport.kt:325)
at kotlinx.coroutines.JobSupport.finalizeFinishingState(JobSupport.kt:242)
at kotlinx.coroutines.JobSupport.tryMakeCompletingSlowPath(JobSupport.kt:910)
at kotlinx.coroutines.JobSupport.tryMakeCompleting(JobSupport.kt:867)
at kotlinx.coroutines.JobSupport.makeCompletingOnce$kotlinx_coroutines_core(JobSupport.kt:832)
at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:100)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
at androidx.compose.ui.test.ApplyingContinuationInterceptor$SendApplyContinuation.resumeWith(ApplyingContinuationInterceptor.kt:65)
at androidx.compose.ui.test.FrameDeferringContinuationInterceptor$FrameDeferredContinuation.resumeWith(FrameDeferringContinuationInterceptor.kt:194)
at kotlinx.coroutines.DispatchedTaskKt.resume(DispatchedTask.kt:179)
at kotlinx.coroutines.DispatchedTaskKt.dispatch(DispatchedTask.kt:168)
at kotlinx.coroutines.CancellableContinuationImpl.dispatchResume(CancellableContinuationImpl.kt:474)
at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl(CancellableContinuationImpl.kt:508)
at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl$default(CancellableContinuationImpl.kt:497)
at kotlinx.coroutines.CancellableContinuationImpl.resumeWith(CancellableContinuationImpl.kt:368)
at kotlinx.coroutines.ResumeOnCompletion.invoke(JobSupport.kt:1391)
at kotlinx.coroutines.JobSupport.completeStateFinalization(JobSupport.kt:320)
at kotlinx.coroutines.JobSupport.tryFinalizeSimpleState(JobSupport.kt:297)
at kotlinx.coroutines.JobSupport.tryMakeCompleting(JobSupport.kt:860)
at kotlinx.coroutines.JobSupport.makeCompletingOnce$kotlinx_coroutines_core(JobSupport.kt:832)
at kotlinx.coroutines.AbstractCoroutine.resumeWith(AbstractCoroutine.kt:100)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115)
at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:103)
at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584)
at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793)
at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697)
at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)
z
can you please file a bug?
v
So this is not supposed to happen? Thanks for confirming. I'll try to gather as much useful info as I can but it's quite rare, happens maybe on 1/100 executions of that code path
z
Just put what you said in this thread in the bug. It sounds like a race condition, so that stack trace should be a good place to start.
Just to ask the obvious though, are you super sure nothing in
Copy code
at <mypackage>(:19) <- helper functions
at <mypackage>(:17) <- helper functions
at <mypackage>.invokeSuspend(:266) <- in a LaunchedEffect
is switching threads?
v
yeah I'm 100% positive, the helper is just a regular function and other code in
LaunchedEffect
doesn't do any context switches
s
Instrumentation tests sometimes do things synchronously. e.g. if you call
setContent
from the test thread, it is possible that
LaunchedEffect
also going to execute in the same thread
v
And with regular I mean non-suspend. It's just a wrapper that dumps the backstack to logs and calls navigate
m
Also make sure that LaunchedEffect is the right call you are observing. I think unlike DisposableEffect, LaunchedEffect does not run syncronously, meaning, in the same frame
v
The stack trace definitely places the original call to a line inside LaunchedEffect, which calls the helper that performs the actual navigation with logging. So I don't think it could be that...
z
if you call
setContent
from the test thread, it is possible that
LaunchedEffect
also going to execute in the same thread
It shouldn’t though, and if it did then it would fail much more regularly since that’s the main recommended way to use it.
m
Right. Just to make sure :p sometimes we miss things like this and waste hours. Not the first time for me.
v
The test doesn't call setContent manually, it creates an AndroidComposeTestRule
z
I don’t see any references to the android main thread stuff in that stack trace, so it looks like it’s a worker thread
s
It is weird that
ApplyingContinuationInterceptor$SendApplyContinuation
and
TestMonotonicClock
is in the trace that is not supposed to be main
z
Definitely looks like something is dispatching this on the wrong thread pretty far upstream
v
I added a log line to print out the thread name it's executing on, I'll try to rerun the tests until I can hit it again
I couldn't reproduce it again so far, so I created the issue without the info: https://issuetracker.google.com/issues/312706742
z
thanks
v
Is there any valuable info I could try to log?
Hit the jackpot!
Copy code
11-23 11:18:55.592  2224  2327 V CX_LoadingPage: LoadingPage LaunchedEffect running on thread Thread[DefaultDispatcher-worker-20,5,main]
z
I think we need to put some thread checks in the test code to help catch this before it gets to user space