Detox wastes time terminating and uninstalling an app right after a fresh simulator launch

[jzaefferer]

What happened?

When running a test, debug log show that Detox immediately after launching a new simulator instance runs EXEC_TRY Uninstalling (once) and EXEC_TRY Terminating (twice), which fails since there's nothing to uninstall or terminate. Afterwards it installs the app, then runs EXEC_TRY Terminating twice more, which again fails, but the run continues anyway.

At this point our beforeAll() hook runs, which runs await device.clearKeychain();. This is followed by 2 more attempts of EXEC_TRY Terminating. After that await device.launchApp() can finally run.

Detox logs below shows the full output from a local run for this. If I'm counting correctly, these unnecessary calls add up to 10s of the total of 60s to start the test run.

When running on Bitrise, I'm also seeing a lot of Terminating and Launching calls, even though we use the default value for device.launchApp({ newInstance: false }). This could be related.

What was the expected behaviour?

Launch simulator, install the app, launch the app. Skip all the uninstall and termination calls.

Was it tested on latest Detox?

• I have tested this issue on the latest Detox release and it still reproduces.

Did your test throw out a timeout?

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

Help us reproduce this issue!

As described above, I'm "just" starting a test.

In what environment did this happen?

Detox version: 20.9.1
React Native version: 0.68.2
Has Fabric (React Native's new rendering system) enabled: no
Node version: 16.18.1
Device model: iPhone 13 simulator
iOS version: 16.x
macOS version: 13.3.1
Xcode version: 14.3
Test-runner (select one): jest

Detox logs

Detox logs (using `--loglevel debug`, with trace the relevant part doesn't fit in my terminal buffer anymore

Determining test suites to run...
11:33:09.296 detox[12330] i child-process:EXEC_CMD applesimutils --list --byType "iPhone 13"
11:33:09.592 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl create "iPhone 13-Detox" "com.apple.CoreSimulator.SimDeviceType.iPhone-13" "com.apple.CoreSimulator.SimRuntime.iOS-16-4"
11:33:09.820 detox[12330] i child-process:EXEC_CMD applesimutils --list --byId 23B15919-AF30-4565-B4C2-C7A188BBC5BF --maxResults 1
11:33:09.967 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl boot 23B15919-AF30-4565-B4C2-C7A188BBC5BF
11:33:09.967 detox[12330] i child-process:EXEC_TRY Booting device 23B15919-AF30-4565-B4C2-C7A188BBC5BF...
11:33:10.453 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl bootstatus 23B15919-AF30-4565-B4C2-C7A188BBC5BF
11:33:33.118 detox[12330] i child-process:EXEC_CMD open -a Simulator --args -CurrentDeviceUDID 23B15919-AF30-4565-B4C2-C7A188BBC5BF
11:33:34.221 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl io 23B15919-AF30-4565-B4C2-C7A188BBC5BF screenshot "/dev/null"
11:33:35.971 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl uninstall 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
11:33:35.972 detox[12330] i child-process:EXEC_TRY Uninstalling com.custom.app...
11:33:36.240 detox[12330] i child-process:EXEC_SUCCESS com.custom.app uninstalled
11:33:36.243 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
11:33:36.243 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:37.846 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:38.019 detox[12330] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
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 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app` (exited with error code 3) (code=3), stdout and stderr:

11:33:38.019 detox[12330] i child-process:EXEC_FAIL
11:33:38.019 detox[12330] 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

11:33:38.020 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl install 23B15919-AF30-4565-B4C2-C7A188BBC5BF "/Users/some-user/dev/mycustom-app/ios/Build/Products/Debug-iphonesimulator/Custom-App.app"
11:33:38.020 detox[12330] i child-process:EXEC_TRY Installing /Users/some-user/dev/mycustom-app/ios/Build/Products/Debug-iphonesimulator/Custom-App.app...
11:33:41.182 detox[12330] i child-process:EXEC_SUCCESS /Users/some-user/dev/mycustom-app/ios/Build/Products/Debug-iphonesimulator/Custom-App.app installed
11:33:41.183 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
11:33:41.184 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:42.828 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:43.034 detox[12330] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
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 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app` (exited with error code 3) (code=3), stdout and stderr:

11:33:43.034 detox[12330] i child-process:EXEC_FAIL
11:33:43.035 detox[12330] 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

11:33:43.987 detox[12330] i child-process:EXEC_CMD applesimutils --byId 23B15919-AF30-4565-B4C2-C7A188BBC5BF --clearKeychain
11:33:43.987 detox[12330] i child-process:EXEC_TRY Clearing Keychain...
11:33:46.721 detox[12330] i child-process:EXEC_SUCCESS Cleared Keychain!
11:33:46.723 detox[12330] i user will launchApp
11:33:46.724 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
11:33:46.724 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:47.890 detox[12330] i child-process:EXEC_TRY Terminating com.custom.app...
11:33:48.839 detox[12330] i child-process:EXEC_FAIL "/usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app" failed with error = ChildProcessError: Command failed: /usr/bin/xcrun simctl terminate 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
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 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app` (exited with error code 3) (code=3), stdout and stderr:

11:33:48.839 detox[12330] i child-process:EXEC_FAIL
11:33:48.839 detox[12330] 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

11:33:48.841 detox[12330] i child-process:EXEC_CMD applesimutils --byId 23B15919-AF30-4565-B4C2-C7A188BBC5BF --bundle com.custom.app --restartSB --setPermissions notifications=YES
11:33:48.841 detox[12330] i child-process:EXEC_TRY Trying to set permissions...
11:33:49.711 detox[12330] i child-process:EXEC_SUCCESS Permissions are set
11:33:49.716 detox[12330] i child-process:EXEC_CMD SIMCTL_CHILD_GULGeneratedClassDisposeDisabled=YES SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/some-user/Library/Detox/ios/35c6a07fc67014ad21c94f5eeb4ba8dc4b840c84/Detox.framework/Detox" /usr/bin/xcrun simctl launch 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app --args -detoxServer ws://localhost:52134 -detoxSessionId 25f0a3f0-72f6-506c-fe39-41006c611f7d -detoxURLOverride detox:user:password -detoxDisableHierarchyDump YES -AppleLanguages '(en-GB)' -AppleLocale en-GB
11:33:49.717 detox[12330] i child-process:EXEC_TRY Launching com.custom.app...
11:33:55.669 detox[12330] i child-process:EXEC_CMD /usr/bin/xcrun simctl get_app_container 23B15919-AF30-4565-B4C2-C7A188BBC5BF com.custom.app
11:33:55.921 detox[12330] i device com.custom.app launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 23B15919-AF30-4565-B4C2-C7A188BBC5BF log stream --level debug --style compact --predicate 'process == "Custom-App"'

11:34:03.873 detox[12330] i user successfully launched app

 RUNS  e2e/recording.e2e.js

Test Suites: 0 of 1 total
Tests:       0 total
Snapshots:   0 total
Time:        57 s, estimated 68 s
████████████████████████████████████████

Device logs

too long for this, find it in a gist instead: https://gist.github.com/jzaefferer/7de9e65aa9ddbf8cf94295cdbd6d8c8c

More data, please!

.detoxrc

module.exports = {
  testRunner: {
    $0: 'jest',
    args: {
      config: 'e2e/jest.config.js',
      _: ['e2e'],
    },
    jest: {
      setupTimeout: 600000,
      reportSpecs: false,
      reportWorkerAssign: false,
    },
    retries: 0,
  },
  session: {
    debugSynchronization: 20000,
  },
  apps: {
    ios: {
      type: 'ios.app',
      build:
        'export RCT_NO_LAUNCH_PACKAGER=true && xcodebuild -workspace ios/tonieapp.xcworkspace -scheme tonieapp -configuration Debug -sdk iphonesimulator -derivedDataPath ios -UseModernBuildSystem=YES -arch x86_64 -quiet',
      binaryPath: './ios/Build/Products/Debug-iphonesimulator/Tonie-App.app',
    },
    'ios.release': {
      type: 'ios.app',
      build:
        'export RCT_NO_LAUNCH_PACKAGER=true && xcodebuild -workspace ios/tonieapp.xcworkspace -scheme tonieapp -configuration Release -sdk iphonesimulator -derivedDataPath ios -UseModernBuildSystem=YES -arch x86_64 -quiet',
      binaryPath: './ios/Build/Products/Release-iphonesimulator/Tonie-App.app',
    },
    android: {
      type: 'android.apk',
      binaryPath: 'SPECIFY_PATH_TO_YOUR_APP_BINARY',
    },
  },
  devices: {
    simulator: {
      type: 'ios.simulator',
      device: {
        type: 'iPhone 13',
      },
    },
    emulator: {
      type: 'android.emulator',
      device: {
        avdName: 'Pixel_3a_API_30_x86',
      },
    },
  },
  configurations: {
    ios: {
      device: 'simulator',
      app: 'ios',
    },
    'ios.release': {
      device: 'simulator',
      app: 'ios.release',
    },
    android: {
      device: 'emulator',
      app: 'android',
    },
  },
};

jest.config.js

module.exports = {
  maxWorkers: 4,
  // if lots of tests fail, there's likely some infrastructure issue
  // running all tests will take a long time, so better to fail early
  bail: 3,
  testTimeout: 300000,
  verbose: true,
  rootDir: '..',
  testMatch: ['<rootDir>/e2e/**/*.e2e.js'],
  reporters: ['detox/runners/jest/reporter'],
  globalSetup: 'detox/runners/jest/globalSetup',
  globalTeardown: 'detox/runners/jest/globalTeardown',
  testEnvironment: 'detox/runners/jest/testEnvironment',
};

launchApp arguments

    await device.launchApp({
      url: `detox:${user}:${password}`,
      languageAndLocale: {
        language: 'en-GB',
        locale: 'en-GB',
      },
      permissions: { notifications: 'YES' },
    });

[jzaefferer]

After reading https://wix.github.io/Detox/docs/config/behavior/#behaviorlaunchapp-enum I tried with behaviour.init.reinstallApp: false and behaviour.launchApp: 'manual', but both just broke my test.

[jzaefferer]

I've now ran into a case where that unnecessary(?) terminate step took over 4 minutes(!), causing the parent launchApp() command to "not finish". The test timed out, despite a 5 minute global timeout.

Here's a screenshot from the trace:

I've uploaded the full trace to this gist: https://gist.github.com/jzaefferer/88057b8c38ed641cec11e27bdc4e65b8

In Perfetto its a bit easier to see the items underneath the terminate step. For some reason the error about a failure to terminate the app only happened after several minutes. I don't see anything there that could explain it:

[RohovDmytro]

Yeah. My logs are also full of installs-reinstalls. Would be nice to shave off those time spent.

[noomorph]

This problem is like sore teeth for me for years already. I know exactly what you mean. Fortunately, we are starting work on this, and this should happen this year, hopefully, end-Q3 or mid-Q4.

[stale]

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.

[jzaefferer]

This is still relevant with the latest release.

[noomorph]

Yes, I'm working on this already in a branch.

[jzaefferer]

@noomorph since that branch is gone - are you still working on it?

[noomorph]

@jzaefferer yeah, I am. I couldn't fit that into a single PR. Currently, I have three different featurefixes around the same layer of code, and I'm a bit like this:

Anyways, I'm looking forward to it happening, and I'm 95% sure this optimization will appear this year (within the next month or two, in the worst case). I'll be not less excited than any of you guys 😊 I'm tired of seeing this on CI as well.