Espresso driver fails to start activity (android compose app)

Hi!
I’m using Appium server v2.0(2.0.0-beta.27), espresso driver ([email protected]) and java-client(8.0.0)
and I’m trying just to start an jetpack compose android app.
It fails when starting the activity.
-from appium server log

2022-03-30 13:08:28:156 [Espresso] Starting activity 'com.lt.android.portal.MainActivity' for package 'com.lt.android.portal'
2022-03-30 13:08:28:157 [WD Proxy] Matched '/appium/device/start_activity' to command name 'startActivity'
2022-03-30 13:08:28:157 [WD Proxy] Proxying [POST /appium/device/start_activity] to [POST http://127.0.0.1:8300/session/7b598010-bd61-4c00-bfd6-bd9792cfb2df/appium/device/start_activity] with body: {"appPackage":"com.lt.android.portal","appActivity":"com.lt.android.portal.MainActivity"}
2022-03-30 13:09:13:198 [WD Proxy] Got response with status 500: {"id":"83accb37-e683-404c-8f61-a656856ba4d4","sessionId":"7b598010-bd61-4c00-bfd6-bd9792cfb2df","value":{"error":"unknown error","message":"java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1648645706650 and now the last time the queue went idle was: 1648645740115. If these numbers are the same your activity might be hogging the event queue.","stacktrace":"java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable ...
2022-03-30 13:09:13:198 [W3C] Matched W3C error code 'unknown error' to UnknownError
2022-03-30 13:09:13:240 [[email protected] (e17142d8)] Encountered internal error running command: An unknown server-side error occurred while processing the command. Original error: java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1648645706650 and now the last time the queue went idle was: 1648645740115. If these numbers are the same your activity might be hogging the event queue.
2022-03-30 13:09:13:240 [[email protected] (e17142d8)] java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1648645706650 and now the last time the queue went idle was: 1648645740115. If these numbers are the same your activity might be hogging the event queue.
2022-03-30 13:09:13:240 [[email protected] (e17142d8)] 	at androidx.test.runner.MonitoringInstrumentation.startActivitySync(MonitoringInstrumentation.java:548)
2022-03-30 13:09:13:240 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.helpers.ActivityHelpers.startActivity(ActivityHelpers.kt:113)
2022-03-30 13:09:13:240 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:27)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:23)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handle(RequestHandler.kt:57)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.http.Router.route(Router.kt:229)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at io.appium.espressoserver.lib.http.Server.serve(Server.kt:51)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 	at java.lang.Thread.run(Thread.java:919)
2022-03-30 13:09:13:241 [[email protected] (e17142d8)] 
  • from logcat:
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[FinalizerWatchdogDaemon,5,system]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:442)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:568)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Daemons$FinalizerWatchdogDaemon.sleepUntilNeeded(Daemons.java:339)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Daemons$FinalizerWatchdogDaemon.runInternal(Daemons.java:319)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Daemons$Daemon.run(Daemons.java:137)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.run(Thread.java:919)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[MonitoringInstrumentation,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:442)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:568)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.app.Instrumentation.startActivitySync(Instrumentation.java:525)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.app.Instrumentation.startActivitySync(Instrumentation.java:464)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation.access$001(MonitoringInstrumentation.java:101)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation$4.call(MonitoringInstrumentation.java:538)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation$4.call(MonitoringInstrumentation.java:535)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.util.concurrent.FutureTask.run(FutureTask.java:266)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.run(Thread.java:919)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[Binder:20365_4,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[Okio Watchdog,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:442)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Object.wait(Object.java:568)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     com.android.okhttp.okio.AsyncTimeout.awaitTimeout(AsyncTimeout.java:313)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     com.android.okhttp.okio.AsyncTimeout.access$000(AsyncTimeout.java:42)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     com.android.okhttp.okio.AsyncTimeout$Watchdog.run(AsyncTimeout.java:288)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[Signal Catcher,5,system]
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[UiAutomation,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.MessageQueue.nativePollOnce(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.MessageQueue.next(MessageQueue.java:336)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.Looper.loop(Looper.java:174)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.HandlerThread.run(HandlerThread.java:67)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[GoogleApiHandler,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.MessageQueue.nativePollOnce(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.MessageQueue.next(MessageQueue.java:336)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.Looper.loop(Looper.java:174)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     android.os.HandlerThread.run(HandlerThread.java:67)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[Thread-3,5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.sleep(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.sleep(Thread.java:440)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.sleep(Thread.java:356)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.EspressoServerRunnerTest.syncComposeClock$lambda-1(EspressoServerRunnerTest.kt:58)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.EspressoServerRunnerTest.$r8$lambda$jauViYNVZZYLGAmqE_UAyxLcTt0(Unknown Source:0)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.EspressoServerRunnerTest$$ExternalSyntheticLambda0.run(Unknown Source:0)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.run(Thread.java:919)
03-30 16:09:11.915 20365 20420 E THREAD_STATE: 
03-30 16:09:11.915 20365 20420 E THREAD_STATE:   Thread[NanoHttpd Request Processor (#1),5,main]
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     dalvik.system.VMStack.getThreadStackTrace(Native Method)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.getStackTrace(Thread.java:1720)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     java.lang.Thread.getAllStackTraces(Thread.java:1796)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation.getThreadState(MonitoringInstrumentation.java:738)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation.dumpThreadStateToOutputs(MonitoringInstrumentation.java:733)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     androidx.test.runner.MonitoringInstrumentation.startActivitySync(MonitoringInstrumentation.java:545)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.helpers.ActivityHelpers.startActivity(ActivityHelpers.kt:113)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:27)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:23)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handle(RequestHandler.kt:57)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.http.Router.route(Router.kt:229)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     io.appium.espressoserver.lib.http.Server.serve(Server.kt:51)
03-30 16:09:11.915 20365 20420 E THREAD_STATE:     fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java
03-30 16:09:11.922 20365 20420 I appium  : Responding to server with error: {error=unknown error, message=java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1648645706650 and now the last time the queue went idle was: 1648645740115. If these numbers are the same your activity might be hogging the event queue., stacktrace=java.lang.RuntimeException: Could not launch intent Intent { act=ACTION_MAIN flg=0x10000000 cmp=com.lt.android.portal/.MainActivity } within 45000 milliseconds. Perhaps the main thread has not gone idle within a reasonable amount of time? There could be an animation or something constantly repainting the screen. Or the activity is doing network calls on creation? See the threaddump logs. For your reference the last time the event queue was idle before your activity launch request was 1648645706650 and now the last time the queue went idle was: 1648645740115. If these numbers are the same your activity might be hogging the event queue.
03-30 16:09:11.922 20365 20420 I appium  : 	at androidx.test.runner.MonitoringInstrumentation.startActivitySync(MonitoringInstrumentation.java:548)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.helpers.ActivityHelpers.startActivity(ActivityHelpers.kt:113)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:27)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.handlers.StartActivity.handleInternal(StartActivity.kt:23)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.handlers.RequestHandler$DefaultImpls.handle(RequestHandler.kt:57)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.handlers.StartActivity.handle(StartActivity.kt:23)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.http.Router.route(Router.kt:229)
03-30 16:09:11.922 20365 20420 I appium  : 	at io.appium.espressoserver.lib.http.Server.serve(Server.kt:51)
03-30 16:09:11.922 20365 20420 I appium  : 	at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945)
03-30 16:09:11.922 20365 20420 I appium  : 	at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192)
03-30 16:09:11.922 20365 20420 I appium  : 	at java.lang.Thread.run(Thread.java:919)
03-30 16:09:11.922 20365 20420 I appium  : }

full logs:

Any suggestion is welcome - I really don’t know where/how to start addressing this issue.
Thanks

1 Like

Hello @ConstantinM, seems I also have a similar query.
Could you please have a look and advice so that I could also reach your level?

The solution to my problem was that I did not have to start an/the “main” to start the app - espresso driver starts the app without having to start the activity for it.
Trying to start the activity I was just trying to start the app while is was already started/running and this caused appium/the test to fail.