Detox Detox on Android emulator hangs with "UI elements are busy" and too slow to function

trafficstars

What happened?

At all times no matter what screen our application is on, Detox moves so slow (1 action per minute) that it's impossible to complete a test. Verbose logs are attached. While Detox does nothing, I see a lot of logs from it saying "UI elements are busy." However, the JS thread and UI thread both show 60fps on the Android profiler as well as the screen is not moving at all and nothing is changing: Screen Shot 2022-07-13 at 6 23 35 PM .

On iOS, Detox performs very well and does not demonstrate any of this behavior. To debug this further, I decided to use the Android native profiler. The render thread looks completely empty. The only things I see are:

While idling, on the main thread, ReactChoreographer is doing some work on every frame: Choreographer#doFrame. Is this normal?

Zoom in on a single frame: Screen Shot 2022-07-13 at 6 33 25 PM

While idling, mqt_js thread is doing some work on every frame: DispatchEventsRunnable. Is this normal?
While idling, mqt_native_modu thread is doing some work on every frame: UIImplementation.updateViewHierarchy. Is this normal?
While idling, RenderThread shows nothing.

Verbose logs are attached below. Is this a known issue with Detox Android? Or, alternatively, is something wrong with our Android app? Thank you for reading.

What was the expected behaviour?

Expect Detox Android to move at a reasonable pace through test actions, similarly to how Detox iOS performs.

Was it tested on latest Detox?

[X] I have tested this issue on the latest Detox release and it still reproduces.

Did your test throw out a timeout?

[X] I have followed the instructions under Identifying which synchronization mechanism causes us to wait too much.

Help us reproduce this issue!

No response

In what environment did this happen?

Detox version: latest 19.7.1 React Native version: 0.65.2 Node version: 16.4.2 Device model: Android AOSP API 31 with hardware acceleration: auto Android version: API 31 Test-runner (select one): jest-circus

Detox logs

Device logs

Here are some verbose logs from detox test -c. After about 5 minutes and barely doing any actions (a few taps, one navigate), Jest hits the timeout limit and the test is terminated.

18:47:00.998 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:01.508 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:02.016 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:02.526 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:03.036 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:03.543 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:04.052 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:04.558 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:05.113 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:05.622 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:06.164 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• UI elements are busy:
  - Reason: UI rendering activity.
• 1 network requests with URLs:
  - URL #1: https://codepush.appcenter.ms/v0.1/public/codepush/report_status/deploy.
• Activity on the React-Native bridge.
18:47:06.757 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• UI elements are busy:
  - Reason: UI rendering activity.
• Activity on the React-Native bridge.
• There are enqueued timers.
18:47:07.272 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:07.783 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:08.295 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:08.803 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:09.314 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:09.822 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:10.336 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:10.848 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:11.361 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:11.874 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:12.387 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:47:12.899 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:13.409 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:13.922 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:14.433 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:14.943 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:15.459 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:15.973 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:16.487 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:16.996 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:17.508 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:18.030 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• UI elements are busy:
  - Reason: UI rendering activity.
• Activity on the React-Native bridge.
18:47:18.543 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:19.054 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:19.564 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:20.075 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:20.589 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:47:21.099 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:21.609 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:22.119 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:22.631 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:23.141 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:23.652 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:24.162 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:24.672 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:25.197 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:25.708 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:26.221 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:26.733 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:27.244 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:27.757 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:28.272 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:28.787 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:29.301 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:29.812 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:30.325 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:30.835 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:31.346 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:31.857 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:32.368 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:32.877 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:33.388 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:33.901 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:34.409 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:34.919 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• Activity on the React-Native bridge.
18:47:35.429 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:35.941 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:36.454 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• Activity on the React-Native bridge.
18:47:36.965 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:37.474 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:37.986 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:38.495 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:39.007 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:39.517 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:40.029 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:40.540 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:41.051 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:41.560 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:42.084 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:42.593 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:43.105 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:43.615 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:44.124 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:44.637 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:45.145 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:45.655 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:46.165 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:46.356 detox[8091] INFO:  at e2e/server/mock-api/utils/utils.js:81:15
 setPersistentMocks was sent
18:47:46.358 detox[8091] INFO:  purchaseMembershipFromAccount Tests is assigned to emulator-15894 (API_31_AOSP)
18:47:46.359 detox[8091] INFO:  purchaseMembershipFromAccount Tests: should sign up and add payment method
18:47:46.872 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:47.385 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:47.893 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:48.403 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:48.915 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:49.424 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:49.936 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:47:50.447 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:50.958 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:51.470 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:51.982 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:52.491 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:53.005 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:53.516 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:54.024 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:54.539 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:55.053 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:47:55.561 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:56.072 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:56.583 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:57.092 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:57.604 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:47:58.116 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
18:47:58.629 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:59.140 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:47:59.651 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:00.161 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:00.673 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:01.183 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:01.691 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:02.201 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:02.711 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:03.219 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:03.728 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:04.240 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:04.752 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:05.260 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:05.772 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:06.285 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:06.795 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:07.306 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:07.819 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:08.330 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:08.841 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:09.354 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• Activity on the React-Native bridge.
18:48:09.865 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:10.374 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:10.885 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:11.393 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:11.902 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:12.411 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:12.922 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:13.433 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:13.942 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:14.452 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:14.962 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:15.473 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:15.987 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:16.497 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:17.007 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:17.519 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:48:18.028 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:18.539 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:19.050 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:19.559 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:20.069 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:20.578 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:21.093 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:21.607 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:22.120 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:48:22.631 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:23.140 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:23.652 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:24.161 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:24.673 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:25.184 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:25.696 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:26.206 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:26.718 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:27.227 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:27.737 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:28.248 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:28.757 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:29.266 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:29.776 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:30.287 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:30.794 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:31.307 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:31.818 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:32.328 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:32.837 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:33.347 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:33.858 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:34.369 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:34.879 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:35.388 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:35.898 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:36.409 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:36.920 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:37.431 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:37.941 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:38.451 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:38.959 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:39.470 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:39.980 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:40.488 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:40.997 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:41.508 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:42.020 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-143-mqt_js" (JS Thread) is executing (JavaScript code).
• Activity on the React-Native bridge.
18:48:42.526 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:43.035 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-144-mqt_native_modules" (Native Modules Thread) is executing (native module calls).
18:48:43.544 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:44.055 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:44.565 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:45.073 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.
18:48:45.582 detox[8091] INFO:  [APP_STATUS] The app is busy with the following tasks:
• UI elements are busy:
  - Reason: UI rendering activity.

More data, please!

No response

Jul 13 '22 22:07 shamilovtim

@jonathanmos @d4vidi looks like there's some good investigation conducted here, let's react somehow, please.

Jul 14 '22 04:07 noomorph

Can't run detox tests on Android due to this. Many tests will get stuck and fail and running the suite takes a very long time due to timeouts.

01:29:47.938 detox[92312] INFO:  [APP_STATUS] The app is busy with the following tasks:
• "LooperIdlingResource-249-mqt_js" (JS Thread) is executing (JavaScript code).
• UI elements are busy:
  - Reason: UI rendering activity.
• Activity on the React-Native bridge.

until a test eventually times out:

    DetoxRuntimeError: Test Failed: Wait for [LooperIdlingResource-249-mqt_js] to become idle timed out

or

    The app has unexpectedly disconnected from Detox server.

Jul 23 '22 00:07 rikur

@shamilovtim It looks to me like an animation that is preventing Detox from seeing the device as idle - perhaps there is an animation happening during tap/navigate? Can you try to use Flipper and see if this gives you any additional information? You can also try to debug this by removing/neutralizing animations one at a time from the test flow and checking at what point it solves the issue -> including app-wide animations if you have them defined for button press, etc.

Jul 24 '22 07:07 jonathanmos

I agree with @jonathanmos. Detox has surfaced that you have some JS logic running endlessly in the background. The native UI thread isn't relevant here.

If you're not convinced (or wish to convince us otherwise), try stripping down your app / screens to something super slim and see whether Detox behaves nicely then.

Jul 24 '22 12:07 d4vidi

Correct me if I'm wrong @d4vidi and @jonathanmos but the reason I didn't think this was an animation was:

There still Detox actions happening. They are just very very slow between every single action.
The message is not "animation pending" (which I've seen before in Detox)
This behavior is also reproducible at app start before 90% of our navigational hierarchy mounts

All of that aside I have already commented out reanimated in the first screen of our app and the behavior persists. Could you let me know if you still think it's still an animation after this?

Jul 24 '22 13:07 shamilovtim

@jonathanmos Could you clarify which Flipper plugin do you think would give me more detail than systrace?

Jul 24 '22 13:07 shamilovtim

React Devtools plugin has a profiler where you can try to find out what is going on the javascript side, or Hermes Debugger plugin to set breakpoints in the js code. Apart from Flipper, you could also try to use MessageQueue.spy() and check what is going over the RN bridge during the tests.

Regarding the other points that you wrote, if I'm not mistaken 'animation pending' occurs only with native animations (useNativeDriver). If there is an animation where every part of the animation is being pushed across the bridge from js then it will appear in the log as 'ui rendering'. Detox may be executing some actions either because of a timing issue (the device is slow so you see the actions happening after they actually happened, and after Detox already sees the device as non-idle) or perhaps because the device is temporarily becoming idle long enough to allow the occassional action to go through. It's also possible that it has nothing to do with animation since the log is pointing at mqt_js - the javascript thread is busy but we don't know why, and while animation is a frequent cause of this, any loop on the javascript would cause the mqt_js thread to be seen as busy. Flipper should be able to help figure out what is actually happening there.

Jul 24 '22 15:07 jonathanmos

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe the issue is still relevant, please test on the latest Detox and report back.

Thank you for your contributions!

For more information on bots in this reporsitory, read this discussion.

Sep 08 '22 16:09 stale[bot]

Still need to test this

Sep 08 '22 17:09 shamilovtim

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe the issue is still relevant, please test on the latest Detox and report back.

Thank you for your contributions!

For more information on bots in this repository, read this discussion.

Oct 09 '22 03:10 stale[bot]

temporary bump

Oct 09 '22 03:10 shamilovtim

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe the issue is still relevant, please test on the latest Detox and report back.

Thank you for your contributions!

For more information on bots in this repository, read this discussion.

Nov 09 '22 05:11 stale[bot]

bump

Nov 09 '22 17:11 shamilovtim

bump, also have this issue

Nov 09 '22 18:11 owens-ben

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe the issue is still relevant, please test on the latest Detox and report back.

Thank you for your contributions!

For more information on bots in this repository, read this discussion.

Dec 11 '22 13:12 stale[bot]

Not stale as a number of contributors have this problem

Dec 18 '22 23:12 shamilovtim

@shamilovtim did you have a chance to test this with the tools that we discussed?

Dec 19 '22 08:12 jonathanmos

@shamilovtim did you have a chance to test this with the tools that we discussed?

This week it's on my backlog. Looking forward to spying the bridge and seeing what's going on like you suggested.

Dec 19 '22 17:12 shamilovtim

Resolved.

I used a bridgespy and found that we have nothing clogging our bridge
I upgraded to Detox 20 and the problem went away

Dec 27 '22 18:12 shamilovtim

for those of you who continue to have this problem here is a bridgespy for you to debug your bridge:

import MessageQueue from 'react-native/Libraries/BatchedBridge/MessageQueue';

export const bridgeSpy = () => {
  MessageQueue.spy(msg => {
    if (msg.module === 'WebSocketModule') {
      return;
    }

    const direction = msg.type ? '🤖 JS -> Native' : '👨 Native -> JS';
    const functionName = [msg.module, msg.method].filter(x => x).join('.');

    console.log(`${direction}: ${functionName}(${msg.args})`);
  });
};

Dec 27 '22 20:12 shamilovtim

2. I upgraded to Detox 20 and the problem went away

Just to chime in here for anyone finding this issue in future.

We were also seeing this on an Android project running Detox 19.8.1 with RN 0.64.4.

Upgrading to the latest 19.X minor release (19.13.0) seems to have eliminated the issue, and halved our test suite run time on Android.

Feb 15 '23 13:02 hanno-jonlay

Detox Detox copied to clipboard

Detox on Android emulator hangs with "UI elements are busy" and too slow to function

What happened?

What was the expected behaviour?

Was it tested on latest Detox?

Did your test throw out a timeout?

Help us reproduce this issue!

In what environment did this happen?

Detox logs

Device logs

More data, please!

Detox
Detox copied to clipboard