Detox tests hang when run on Bitrise

[dinushiherath]

Description

I am trying to run our Detox tests on Bitrise and finding that the tests hang and eventually time out. This is only happening when running the tests on Bitrise, when running the tests locally they run without any issues.

When I run the tests on Bitrise the test fails with the following error:

10:11:42.085 detox[20871] i device org.reactjs.native.example.NewsTalk launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 99734B84-23EB-42F7-85D9-654634B5CFB6 log stream --level debug --style compact --predicate 'process == "NewsTalk"'
10:11:52.098 detox[20871] i ws-client:APP_STATUS Failed to execute the current status query.
10:21:31.570 detox[20871] i lifecycle Live Now: should load the Live Now screen correctly
10:21:31.573 detox[20871] i lifecycle Live Now: should load the Live Now screen correctly [FAIL]
10:21:31.623 detox[20871] i ws-client:PENDING_REQUESTS The app has not responded to the network requests below:
  (id = -1000) isReady: {}
Unresponded network requests might result in timeout errors in Detox tests.
10:21:31.636 detox[20870] E ws-server connection :49292<->:49293
10:21:31.644 detox[20871] i child-process:EXEC_CMD /usr/bin/xcrun simctl shutdown 99734B84-23EB-42F7-85D9-654634B5CFB6
10:21:31.644 detox[20871] i child-process:EXEC_TRY Shutting down 99734B84-23EB-42F7-85D9-654634B5CFB6...
10:21:33.327 detox[20870] E ws-server connection :49292<->:49803
10:21:35.810 detox[20871] i child-process:EXEC_SUCCESS 99734B84-23EB-42F7-85D9-654634B5CFB6 shut down
FAIL e2e/tests/LiveNow.test.js (695.897 s)
  Live Now
    ✕ should load the Live Now screen correctly (4 ms)
  ● Live Now › should load the Live Now screen correctly
    thrown: "Exceeded timeout of 600000 ms for a hook.
    Use jest.setTimeout(newTimeout) to increase the timeout value, if this is a long-running test."
      4 |
      5 | describe('Live Now', () => {
    > 6 |   beforeAll(async () => {
        |   ^
      7 |     await device.launchApp({
      8 |       launchArgs: {
      9 |         DTXEnableVerboseSyncSystem: 'YES',
      at beforeAll (e2e/tests/LiveNow.test.js:6:3)
      at Object.describe (e2e/tests/LiveNow.test.js:5:1)
10:21:36.048 detox[20870] E lifecycle Command failed with exit code = 1:
jest --config e2e/jest.config.js
10:21:36.049 detox[20870] i ws-server Detox server has been closed gracefully
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

I also tried to run the tests manually on the Bitrise machine but the tests failed this time as well. However this time I could see more detailed log

vm-osx-ventura-g2:git vagrant$ 
vm-osx-ventura-g2:git vagrant$ yarn e2e:test:ios.sim.debug
$ export SKIP_LOGIN=true && detox test --configuration ios.sim.debug --cleanup --loglevel verbose
06:28:17.417 detox[32184] i ws-server Detox server listening on localhost:60514...
06:28:17.442 detox[32184] B lifecycle jest --config e2e/jest.config.js
06:28:19.519 detox[32184] B ws-server connection :60514<->:60524
06:28:19.914 detox[32192] i child-process:EXEC_CMD applesimutils --list --byType "iPhone 14"
06:28:20.987 detox[32192] i child-process:EXEC_CMD applesimutils --list --byId 99734B84-23EB-42F7-85D9-654634B5CFB6 --maxResults 1
06:28:21.709 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl uninstall 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
06:28:21.709 detox[32192] i child-process:EXEC_TRY Uninstalling org.reactjs.native.example.NewsTalk...
06:28:22.321 detox[32192] i child-process:EXEC_SUCCESS org.reactjs.native.example.NewsTalk uninstalled
06:28:22.325 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
06:28:22.326 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:23.883 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:24.463 detox[32192] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate
 `/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk` (exited with error code 3) (code=3), stdout and stderr:

06:28:24.464 detox[32192] i child-process:EXEC_FAIL 
06:28:24.464 detox[32192] i child-process:EXEC_FAIL An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate

06:28:24.466 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl install 99734B84-23EB-42F7-85D9-654634B5CFB6 "/Users/vagrant/git/ios/build/Build/Products/Debug-iphonesimulator/NewsTalk.app"
06:28:24.466 detox[32192] i child-process:EXEC_TRY Installing /Users/vagrant/git/ios/build/Build/Products/Debug-iphonesimulator/NewsTalk.app...
06:28:26.112 detox[32192] i child-process:EXEC_SUCCESS /Users/vagrant/git/ios/build/Build/Products/Debug-iphonesimulator/NewsTalk.app installed
06:28:26.114 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
06:28:26.114 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:28.183 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:28.823 detox[32192] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate
 `/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk` (exited with error code 3) (code=3), stdout and stderr:

06:28:28.823 detox[32192] i child-process:EXEC_FAIL 
06:28:28.824 detox[32192] i child-process:EXEC_FAIL An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate

06:28:29.043 detox[32192] i lifecycle LiveNow.test.js is assigned to 99734B84-23EB-42F7-85D9-654634B5CFB6 (iPhone 14)
06:28:29.057 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
06:28:29.058 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:30.616 detox[32192] i child-process:EXEC_TRY Terminating org.reactjs.native.example.NewsTalk...
06:28:31.124 detox[32192] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate
 `/usr/bin/xcrun simctl terminate 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk` (exited with error code 3) (code=3), stdout and stderr:

06:28:31.124 detox[32192] i child-process:EXEC_FAIL 
06:28:31.125 detox[32192] i child-process:EXEC_FAIL An error was encountered processing the command (domain=NSPOSIXErrorDomain, code=3):
Simulator device returned an error for the requested operation.
found nothing to terminate
Underlying error (domain=NSPOSIXErrorDomain, code=3):
	The operation couldn’t be completed. found nothing to terminate
	found nothing to terminate

06:28:31.127 detox[32192] i child-process:EXEC_CMD SIMCTL_CHILD_GULGeneratedClassDisposeDisabled=YES SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/vagrant/Library/Detox/ios/9a30716e98a6d3c0ba720bd6ce6731c9867afdaf/Detox.framework/Detox" /usr/bin/xcrun simctl launch 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk --args -detoxServer ws://localhost:60514 -detoxSessionId 85c72ee7-1be0-ed6b-c354-00b3b566be37 -DTXEnableVerboseSyncSystem YES -DTXEnableVerboseSyncResources YES -detoxURLBlacklistRegex '.*ap-playerservices.streamtheworld.com.*,.*//l.ffx.io/.*' -detoxDisableHierarchyDump YES
06:28:31.127 detox[32192] i child-process:EXEC_TRY Launching org.reactjs.native.example.NewsTalk...
06:28:31.723 detox[32192] i child-process:EXEC_CMD /usr/bin/xcrun simctl get_app_container 99734B84-23EB-42F7-85D9-654634B5CFB6 org.reactjs.native.example.NewsTalk
06:28:32.805 detox[32184] B ws-server connection :60514<->:60579
06:28:33.145 detox[32192] i device org.reactjs.native.example.NewsTalk launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 99734B84-23EB-42F7-85D9-654634B5CFB6 log stream --level debug --style compact --predicate 'process == "NewsTalk"'
06:28:43.594 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• 3 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 3.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 5.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #3:
    + JS timer ID: 9.
    + Duration: 0.001.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• Run loop "JS Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
06:28:53.598 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 242.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 246.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:03.603 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 358.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 366.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:13.610 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 478.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 486.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:23.616 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 1 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 598.
    + Duration: 1.
    + Is recurring: NO.
• There are 4 work items pending on the dispatch queue: "RN Module: UIManager (<OS_dispatch_queue_serial: com.facebook.react.ShadowQueue>)".
• The event "Runloop Perform Block" is taking place with object: "JS Run Loop".
• Run loop "Main Run Loop" is awake.
• Run loop "JS Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:33.621 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 714.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 718.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:43.625 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 834.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 838.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• There are 1 work items pending on the dispatch queue: "Main Queue (<OS_dispatch_queue_main: com.apple.main-thread>)".
06:29:53.632 detox[32192] i ws-client:APP_STATUS The app is busy with the following tasks:
• 2 enqueued JavaScript timers:
  - Timer #1:
    + JS timer ID: 958.
    + Duration: 1.
    + Is recurring: NO.
  - Timer #2:
    + JS timer ID: 966.
    + Duration: 1.
    + Is recurring: NO.
• Run loop "Main Run Loop" is awake.
• 1 enqueued native timers:
  - Timer #1:
    + Fire date: none.
    + Time until fire: 0.000.
    + Repeat interval: 0.

So it seems like Detox is pending on some background processes to finish.

To stop this from happening I've disabled synchronisation in my test but this doesn't seem to prevent Detox from waiting for the timers to finish e.g.

/* eslint-env detox/detox, mocha */

const liveNowHeaderText = 'appbar-content-title-text'

describe('Live Now', () => {
  beforeAll(async () => {
    await device.launchApp({
      launchArgs: {
        DTXEnableVerboseSyncSystem: 'YES',
        DTXEnableVerboseSyncResources: 'YES',
        detoxURLBlacklistRegex: ['.*ap-playerservices.streamtheworld.com.*', '.*l.ffx.io.*'],
      },
      newInstance: true,
    })
    await device.disableSynchronization()
  })

  // TODO: Complete Live Now screen test, created RAD-1773 for this task
  it('should load the Live Now screen correctly', async () => {
    await expect(element(by.id(liveNowHeaderText))).toHaveText('Live Now')
  })
})

The tests run fine on my local machine and only seems to have this problem on the Bitrise machine. Does anyone have any ideas on what might be causing the issue or how to debug this further?

Your environment

Detox version: 20.5.0
React Native version: 0.71.3
Node version:
Device model: macOS 13.2 (Ventura)Intel Medium
OS: Xcode 14.2.x
Test-runner (select one): jest

[yaroslav-n]

Hey @dinushiherath, have you figured it out?

[dinushiherath]

Hi @yaroslav-n, Yes we managed to resolve the issue. It turned out to be a mismatch between the environment variables between local and Bitrise.

[micahdasMA]

Hi @dinushiherath, I know it's been a long time, but do you remember how you identified the mismatch with the env variables?