Detox icon indicating copy to clipboard operation
Detox copied to clipboard

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

Open jzaefferer opened this issue 2 years ago • 19 comments

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?

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

Did your test throw out a timeout?

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 avatar May 31 '23 10:05 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 avatar May 31 '23 14:05 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: Screenshot 2023-06-01 at 14 04 04

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:

Screenshot 2023-06-01 at 14 10 47

jzaefferer avatar Jun 01 '23 12:06 jzaefferer

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

RohovDmytro avatar Jun 01 '23 17:06 RohovDmytro

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.

noomorph avatar Jun 02 '23 11:06 noomorph

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.

stale[bot] avatar Jul 15 '23 00:07 stale[bot]

This is still relevant with the latest release.

jzaefferer avatar Jul 15 '23 05:07 jzaefferer

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

noomorph avatar Aug 23 '23 08:08 noomorph

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

jzaefferer avatar Nov 02 '23 12:11 jzaefferer

@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.

noomorph avatar Nov 02 '23 13:11 noomorph

Sounds good. Good luck! I'd love to help, but it would probably take way too long to get familiar with the relevant code 🙈

jzaefferer avatar Nov 02 '23 17:11 jzaefferer

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.

stale[bot] avatar Dec 15 '23 04:12 stale[bot]

Still relevant, given the activity of a maintainer 😎

jzaefferer avatar Dec 15 '23 08:12 jzaefferer

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.

stale[bot] avatar Mar 17 '24 08:03 stale[bot]

Still relevant, as above

jzaefferer avatar Mar 17 '24 09:03 jzaefferer

@jzaefferer , I absolutely agree with you. If this hurts too much, try setting up --reuse or reinstallApp: false, and add a custom device setup (e.g. in custom jest environment or setupAfterEnv). A simplistic tweak like this may have some caveats for local use, but should be fine for CI use where you can set an expectation that the app will be installed only once.

I'll see if I can start working 1 day per sprint on this, since I cannot allocate a good interrupted week of work two until May-June. I myself am not very fond of this not moving anywhere. ☹️

noomorph avatar Mar 17 '24 09:03 noomorph