Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unable to control >1 simulator when running parallel Jest tests #1320

Closed
cs01 opened this issue Apr 19, 2019 · 13 comments
Closed

Unable to control >1 simulator when running parallel Jest tests #1320

cs01 opened this issue Apr 19, 2019 · 13 comments

Comments

@cs01
Copy link
Contributor

cs01 commented Apr 19, 2019

Detox: 12.4.0
Node: v8.11.1
device: iPhone 7 Plus
Xcode: 10.2
macOS: Mojave 10.14.4
jest: 24.7.1

This issue is similar to #1004. When running Jest in our build system (not via detox cli) with 2 workers and 2 tests, only one simulator starts and runs. The other never starts, and the test times out.

Only one simulator starts

This is an invocation of Jest in our source tree where only one simulator starts despite having two Jest workers. You can see both tests are run in parallel, and the Detox server is started for both (so detox.init() was called in beforeAll() for both), but things just seem to stop when the simulator call is supposed to occur, almost like the first worker gets a mutex on xcrun.

I manually remove ~/Library/Detox/device.registry.state.lock at the start of the test and call Jest.

>> jest [args for our build system]
detox[99405] INFO:  [DetoxServer.js] server listening on localhost:59636...
detox[99404] INFO:  [DetoxServer.js] server listening on localhost:59637...
detox[99405] DEBUG: [AsyncWebSocket.js/WEBSOCKET_OPEN] opened web socket to: ws://localhost:59636
detox[99404] DEBUG: [AsyncWebSocket.js/WEBSOCKET_OPEN] opened web socket to: ws://localhost:59637
detox[99405] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=4c9d4004-c7dc-2059-ce60-8efd17949e7e
detox[99404] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=2b84c9e5-8f16-6fb8-8b2b-35f8d070ed5d
detox[99404] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=2b84c9e5-8f16-6fb8-8b2b-35f8d070ed5d
detox[99405] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=4c9d4004-c7dc-2059-ce60-8efd17949e7e
detox[99404] DEBUG: [exec.js/EXEC_CMD, #0] /usr/bin/xcrun simctl list -j
detox[99404] DEBUG: [exec.js/EXEC_CMD, #1] applesimutils --list --byType "iPhone 7 Plus" --byOS "12.2"
detox[99404] DEBUG: [exec.js/EXEC_TRY, #1] Searching for device matching iPhone 7 Plus...
detox[99404] DEBUG: [exec.js/EXEC_CMD, #2] applesimutils --list --byId "CD354060-0339-4722-A6F4-9600E99CDEF0"
detox[99404] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest
detox[99404] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling org.reactjs.native.example.DemoReactNativeJest...
detox[99404] DEBUG: [exec.js/EXEC_SUCCESS, #3] org.reactjs.native.example.DemoReactNativeJest uninstalled
detox[99404] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install CD354060-0339-4722-A6F4-9600E99CDEF0 "/Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app"
detox[99404] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app...
detox[99404] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app installed
detox[99404] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest
detox[99404] DEBUG: [exec.js/EXEC_TRY, #5] Terminating org.reactjs.native.example.DemoReactNativeJest...
detox[99404] DEBUG: [exec.js/EXEC_SUCCESS, #5] org.reactjs.native.example.DemoReactNativeJest terminated
detox[99404] DEBUG: [exec.js/EXEC_CMD, #6] /bin/cat /dev/null >/Users/user/Library/Developer/CoreSimulator/Devices/CD354060-0339-4722-A6F4-9600E99CDEF0/data/tmp/detox.last_launch_app_log.out 2>/Users/user/Library/Developer/CoreSimulator/Devices/CD354060-0339-4722-A6F4-9600E99CDEF0/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/user/Library/Detox/ios/96bbdd7699384cf914cbef73d35a0c1c7fd4a1ad/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest --args -detoxServer "ws://localhost:59637" -detoxSessionId "2b84c9e5-8f16-6fb8-8b2b-35f8d070ed5d"
detox[99404] DEBUG: [exec.js/EXEC_TRY, #6] Launching org.reactjs.native.example.DemoReactNativeJest...
detox[10017] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=ac539a60-0988-8bb5-7a12-045cd00e7792)
detox[10017] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=ac539a60-0988-8bb5-7a12-045cd00e7792
detox[10017] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=ac539a60-0988-8bb5-7a12-045cd00e7792
 PASS  xplat/js/gauntlet/oculus-twilight-e2e/basic-init2-test.js (6.908s)
detox[10017] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=ac539a60-0988-8bb5-7a12-045cd00e7792
detox[10017] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=ac539a60-0988-8bb5-7a12-045cd00e7792
...

Timeout - Async callback was not invoked within the 40000ms timeout specified by jest.setTimeout.Error: Timeout - Async callback was not invoked within the 40000ms timeout specified by jest.setTimeout.

  at mapper (npm-jest-jasmine2-24.7.1.zip/node_modules/jest-jasmine2/build/queueRunner.js:25:45)

● basic initialization smoke test › loads main screen

TypeError: Cannot read property 'id' of undefined

successful run of demo-react-native-jest

This is a successful run of the Detox example. You can see the two simulators get started in parallel.

>> yarn run detox test e2e --configuration ios.sim.release --loglevel verbose --workers 2
Using globally installed version of Yarn
yarn run v1.12.1
$ /Users/user/git/Detox/examples/demo-react-native-jest/node_modules/.bin/detox test e2e --configuration ios.sim.release --loglevel verbose --workers 2
detox[86153] INFO:  [test.js] configuration="ios.sim.release" loglevel="verbose" artifactsLocation="artifacts/ios.sim.release.2019-04-19 22-15-30Z" recordLogs="none" takeScreenshots="manual" recordVideos="none" recordPerformance="none" node_modules/.bin/jest --config=e2e/config.json --maxWorkers=2 '--testNamePattern=^((?!:android:).)*$' e2e
detox[86159] INFO:  [DetoxServer.js] server listening on localhost:58030...
detox[86158] INFO:  [DetoxServer.js] server listening on localhost:58031...
detox[86158] DEBUG: [AsyncWebSocket.js/WEBSOCKET_OPEN] opened web socket to: ws://localhost:58031
detox[86159] DEBUG: [AsyncWebSocket.js/WEBSOCKET_OPEN] opened web socket to: ws://localhost:58030
detox[86158] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
detox[86158] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
detox[86159] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3
detox[86159] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3
detox[86158] DEBUG: [exec.js/EXEC_CMD, #0] /usr/bin/xcrun simctl list -j
detox[86158] DEBUG: [exec.js/EXEC_CMD, #1] applesimutils --list --byType "iPhone 7 Plus" --byOS "12.2"
detox[86158] DEBUG: [exec.js/EXEC_TRY, #1] Searching for device matching iPhone 7 Plus...
detox[86158] DEBUG: [exec.js/EXEC_CMD, #2] applesimutils --list --byId "CD354060-0339-4722-A6F4-9600E99CDEF0"
detox[86159] DEBUG: [exec.js/EXEC_CMD, #0] /usr/bin/xcrun simctl list -j
detox[86159] DEBUG: [exec.js/EXEC_CMD, #1] applesimutils --list --byType "iPhone 7 Plus" --byOS "12.2"
detox[86159] DEBUG: [exec.js/EXEC_TRY, #1] Searching for device matching iPhone 7 Plus...
detox[86158] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest
detox[86158] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling org.reactjs.native.example.DemoReactNativeJest...
detox[86159] DEBUG: [exec.js/EXEC_CMD, #2] applesimutils --list --byId "DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE"
detox[86159] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE org.reactjs.native.example.DemoReactNativeJest
detox[86159] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling org.reactjs.native.example.DemoReactNativeJest...
detox[86158] DEBUG: [exec.js/EXEC_SUCCESS, #3] org.reactjs.native.example.DemoReactNativeJest uninstalled
detox[86158] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install CD354060-0339-4722-A6F4-9600E99CDEF0 "/Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app"
detox[86158] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app...
detox[86159] DEBUG: [exec.js/EXEC_SUCCESS, #3] org.reactjs.native.example.DemoReactNativeJest uninstalled
detox[86159] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE "/Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app"
detox[86159] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app...
detox[86158] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app installed
detox[86158] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest
detox[86158] DEBUG: [exec.js/EXEC_TRY, #5] Terminating org.reactjs.native.example.DemoReactNativeJest...
detox[86158] DEBUG: [exec.js/EXEC_SUCCESS, #5] org.reactjs.native.example.DemoReactNativeJest terminated
detox[86158] DEBUG: [exec.js/EXEC_CMD, #6] /bin/cat /dev/null >/Users/user/Library/Developer/CoreSimulator/Devices/CD354060-0339-4722-A6F4-9600E99CDEF0/data/tmp/detox.last_launch_app_log.out 2>/Users/user/Library/Developer/CoreSimulator/Devices/CD354060-0339-4722-A6F4-9600E99CDEF0/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/user/Library/Detox/ios/96bbdd7699384cf914cbef73d35a0c1c7fd4a1ad/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err CD354060-0339-4722-A6F4-9600E99CDEF0 org.reactjs.native.example.DemoReactNativeJest --args -detoxServer "ws://localhost:58031" -detoxSessionId "6cf444fb-34ff-ed32-390d-4abc84e67667"
detox[86158] DEBUG: [exec.js/EXEC_TRY, #6] Launching org.reactjs.native.example.DemoReactNativeJest...
detox[86158] INFO:  [AppleSimUtils.js] org.reactjs.native.example.DemoReactNativeJest launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/user/Library/Developer/CoreSimulator/Devices/CD354060-0339-4722-A6F4-9600E99CDEF0/data/tmp/detox.last_launch_app_log.{out,err}
detox[86159] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/user/git/Detox/examples/demo-react-native-jest/ios/build/Build/Products/Release-iphonesimulator/DemoReactNativeJest.app installed
detox[86158] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667)
detox[86159] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE org.reactjs.native.example.DemoReactNativeJest
detox[86159] DEBUG: [exec.js/EXEC_TRY, #5] Terminating org.reactjs.native.example.DemoReactNativeJest...
detox[86159] DEBUG: [exec.js/EXEC_SUCCESS, #5] org.reactjs.native.example.DemoReactNativeJest terminated
detox[86159] DEBUG: [exec.js/EXEC_CMD, #6] /bin/cat /dev/null >/Users/user/Library/Developer/CoreSimulator/Devices/DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE/data/tmp/detox.last_launch_app_log.out 2>/Users/user/Library/Developer/CoreSimulator/Devices/DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/user/Library/Detox/ios/96bbdd7699384cf914cbef73d35a0c1c7fd4a1ad/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE org.reactjs.native.example.DemoReactNativeJest --args -detoxServer "ws://localhost:58030" -detoxSessionId "ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3"
detox[86159] DEBUG: [exec.js/EXEC_TRY, #6] Launching org.reactjs.native.example.DemoReactNativeJest...
detox[86158] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
detox[86158] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
detox[86159] INFO:  [AppleSimUtils.js] org.reactjs.native.example.DemoReactNativeJest launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/user/Library/Developer/CoreSimulator/Devices/DA69BE9E-5BB5-4E7A-B57D-58DFD44E25FE/data/tmp/detox.last_launch_app_log.{out,err}
detox[86159] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3)
detox[86159] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3
detox[86159] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3
 PASS  e2e/app.test.js (8.721s)
detox[86158] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
detox[86158] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=6cf444fb-34ff-ed32-390d-4abc84e67667
 PASS  e2e/app2.test.js (9.673s)

Test Suites: 2 passed, 2 total
Tests:       6 passed, 6 total
Snapshots:   0 total
Time:        9.999s, estimated 22s
Ran all test suites matching /e2e/i with tests matching "^((?!:android:).)*$".
detox[86159] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=ab4df2cc-635b-d5e9-7f9e-84797ed0c1f3
✨  Done in 10.97s.
@noomorph
Copy link
Collaborator

@cs01, could you please remake the logs, but in log level trace mode? Thanks in advance

@noomorph
Copy link
Collaborator

And why do you remove the lock file? Not sure if I understood your reasoning behind that.

@cs01
Copy link
Contributor Author

cs01 commented Apr 22, 2019

Thank you for the quick response! I will post trace logs soon.

And why do you remove the lock file? Not sure if I understood your reasoning behind that.

To ensure consistent simulator state between runs and avoid creating new simulators, as found by trial and error and then later in the detox documentation.

@cs01
Copy link
Contributor Author

cs01 commented Apr 23, 2019

@noomorph
Copy link
Collaborator

noomorph commented Apr 23, 2019

So, you don't use Detox CLI. Okay.
Do you use global setup? (See examples/demo-react-native-jest/e2e-reuse/global.js for the reference: #1328)

@cs01
Copy link
Contributor Author

cs01 commented Apr 23, 2019

I don't use the global setup but I do add beforeAll and beforeEach calls. Is the global setup required? It might be a little tricky for me since we are using babel and import(not require).

It is interesting that the init and cleanup calls are done back-to-back in the global.js example you pointed me to. Doesn't the cleanup immediately undo the init?

@rotemmiz
Copy link
Contributor

Hey @cs01, there's a lot of data missing here, what is the exact command params you run jest with?
Also, what are the env vars being passed to jest?

Try running the demo-react-native-jest with verbose logging, and you should see exactly how detox calls jest cli tool, you may be missing a param.

@cs01
Copy link
Contributor Author

cs01 commented Apr 23, 2019

I am running Jest with the following arguments:

jest test-folder --testRegex=.*js --skipFilter --detectOpenHandles --forceExit --maxWorkers=2

I am passing the following config to Detox:

    const config = {
      'test-runner': 'jest',
      configurations: {
        myconfig: {
          binaryPath: 'myapp.app',
          type: 'ios.simulator',
          name: 'iPhone 6s',
        },
      },
    };

I am not setting any environment variables.

I tried comparing the trace output of demo-react-native-jest (as I pasted in my initial post), but couldn't see why the simulators were behaving differently.

@noomorph
Copy link
Collaborator

noomorph commented Apr 25, 2019

It is interesting that the init and cleanup calls are done back-to-back in the global.js example you pointed me to. Doesn't the cleanup immediately undo the init?

It was a surprise to me too, but the idea is to install the app in init and release the lock in cleanup. The cleanup does not do much (and it does not uninstall anything) — don't hesitate to look up in the code:

Detox/detox/src/Detox.js

Lines 80 to 98 in 789ded5

async cleanup() {
await this.artifactsManager.onAfterAll();
if (this.client) {
await this.client.cleanup();
}
if (this.device) {
await this.device._cleanup();
}
if (this.server) {
this.server.close();
}
if (argparse.getArgValue('cleanup') && this.device) {
await this.device.shutdown();
}
}

async cleanup(deviceId, bundleId) {
await this.deviceRegistry.freeDevice(deviceId);
await super.cleanup(deviceId, bundleId);
}

@noomorph
Copy link
Collaborator

noomorph commented Apr 25, 2019

@cs01, as for your issue, I have a hunch that one of the workers hangs up waiting for a free device.
I suggest you add more log.trace() stuff across such places in the code to verify or reject my hypothesis.

Please try doing it yourself — I hope it is going to be fruitful and helps to locate the exact place where your code gets stuck. Afterward, we could arrange a PR that extends logging a bit, to help other people using Detox that hit the same situation you are (were) in.

@cs01
Copy link
Contributor Author

cs01 commented Apr 29, 2019

I have definitely already looked around the detox source and learned a lot about it 😄 .

Turned out I was running my test in a config with several other Jest projects. By making my own config and calling it directly (not along with other projects), the workers didn't freeze up.

@cs01 cs01 closed this as completed Apr 29, 2019
@noomorph noomorph reopened this Apr 30, 2019
@noomorph
Copy link
Collaborator

noomorph commented Apr 30, 2019

Chad, please, let's do post mortem. Any wild ideas that could have helped people in your shoes to figure out they are doing something terribly wrong? :) I'd be happy to improve user-friendliness in some places for sure.

How did the project structure look like, in general?

@no-response
Copy link

no-response bot commented May 7, 2019

This issue has been automatically closed because there has been no response to our request for more information from the original author.

@no-response no-response bot closed this as completed May 7, 2019
@lock lock bot locked as resolved and limited conversation to collaborators May 10, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants