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

Detox + Expo + jest : timeout on opening the app #1422

Closed
1 task done
jeromecornet opened this issue Jun 2, 2019 · 38 comments
Closed
1 task done

Detox + Expo + jest : timeout on opening the app #1422

jeromecornet opened this issue Jun 2, 2019 · 38 comments

Comments

@jeromecornet
Copy link

Describe the bug
Detox tests timeout waiting for the return of app opening methods.
using the detox-expo-helpers , both reloadApp() and device.openUrl({ url }) hang while waiting for the device response.

It looks like the Device Driver deliverPayload does not return.

To Reproduce

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

Here is a repo (basically I just ran expo init and detox init -r jest)
https://github.com/jeromecornet/expotest

You will note that device.launchApp without a url returns, but does not with a url launch parameter.

Also I can use the standalone app (not via the expo client) and it works fine, this seems to be specific to the expo client.

Expected behavior
Both launch methods should return.

Environment (please complete the following information):

  • Detox: 12.10.2
  • React Native: 0.57.1 (from expo sdk 32.0.0)
  • Node: 6.7.0
  • Device: iOS simulator, iPhone 8
  • Xcode: 10.2.1
  • iOS: 12.1
  • macOS: 10.14.5

with expo 32.0.0

Device and Verbose Detox Logs

detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBootDevice({ coldBoot: false,
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4' })
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeUninstallApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[54371] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[54371] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #3] 
detox[54371] DEBUG: [exec.js/EXEC_SUCCESS, #3] host.exp.Exponent uninstalled
detox[54371] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install 2F0E2EDF-A080-4757-90C4-976F1445D7C4 "/Users/jeromecornet/src/expotest/bin/expo.app"
detox[54371] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/jeromecornet/src/expotest/bin/expo.app...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #4] 
detox[54371] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/jeromecornet/src/expotest/bin/expo.app installed
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[54371] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[54371] DEBUG: [exec.js/EXEC_TRY, #5] Terminating host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #5] 
detox[54371] DEBUG: [exec.js/EXEC_SUCCESS, #5] host.exp.Exponent terminated
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098' } })
detox[54371] DEBUG: [exec.js/EXEC_CMD, #6] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:58963" -detoxSessionId "e36ef041-2bde-00df-d586-44b10a2a6098"
detox[54371] DEBUG: [exec.js/EXEC_TRY, #6] Launching host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #6] host.exp.Exponent: 54408

detox[54371] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[54408] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098' },
  pid: 54408 })
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=testee action=ready (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"ready","messageId":-1000,"params":{}}
 
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"waitForActive","params":{},"messageId":1}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=waitForActive (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=testee action=waitForActiveDone (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"waitForActiveDone","messageId":1,"params":{}}
 
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeAll()
Example: should load the app
detox[54371] TRACE: [Detox.js/DETOX_BEFORE_EACH] running test: "Example should load the app"
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeEach({ title: 'should load the app',
  fullName: 'Example should load the app',
  status: 'running' })
  console.log e2e/firstTest.spec.js:6
    Lauching using reloadApp

detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[54371] DEBUG: [exec.js/EXEC_CMD, #7] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[54371] DEBUG: [exec.js/EXEC_TRY, #7] Terminating host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #7] 
detox[54371] DEBUG: [exec.js/EXEC_SUCCESS, #7] host.exp.Exponent terminated
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098',
     EXKernelDisableNuxDefaultsKey: true,
     detoxURLBlacklistRegex:
      '\\("http://192.168.86.24:19005/onchange","https://e.crashlytics.com/spi/v2/events"\\)',
     detoxURLOverride: 'exp://192.168.86.24:19004',
     detoxSourceAppOverride: 'host.exp.exponent' } })
detox[54371] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [exec.js/EXEC_CMD, #8] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/ExpoDetoxHook/ios/d49fa2ddb665bfbaeb7e286b34efc73912f59c66/ExpoDetoxHook.framework/ExpoDetoxHook:/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:58963" -detoxSessionId "e36ef041-2bde-00df-d586-44b10a2a6098" -EXKernelDisableNuxDefaultsKey "true" -detoxURLBlacklistRegex "\("http://192.168.86.24:19005/onchange","https://e.crashlytics.com/spi/v2/events"\)" -detoxURLOverride "exp://192.168.86.24:19004" -detoxSourceAppOverride "host.exp.exponent"
detox[54371] DEBUG: [exec.js/EXEC_TRY, #8] Launching host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #8] host.exp.Exponent: 54435

detox[54371] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[54435] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098',
     EXKernelDisableNuxDefaultsKey: true,
     detoxURLBlacklistRegex:
      '\\("http://192.168.86.24:19005/onchange","https://e.crashlytics.com/spi/v2/events"\\)',
     detoxURLOverride: 'exp://192.168.86.24:19004',
     detoxSourceAppOverride: 'host.exp.exponent' },
  pid: 54435 })
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
Example: should load the app [FAIL]
Example: should open the app URL
detox[54371] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should load the app"
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({ title: 'should load the app',
  fullName: 'Example should load the app',
  status: 'failed' })
detox[54371] TRACE: [Detox.js/DETOX_BEFORE_EACH] running test: "Example should open the app URL"
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeEach({ title: 'should open the app URL',
  fullName: 'Example should open the app URL',
  status: 'running' })
  console.log e2e/firstTest.spec.js:13
    Lauching expo

detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[54371] DEBUG: [exec.js/EXEC_CMD, #9] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[54371] DEBUG: [exec.js/EXEC_TRY, #9] Terminating host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #9] 
detox[54371] DEBUG: [exec.js/EXEC_SUCCESS, #9] host.exp.Exponent terminated
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098',
     EXKernelDisableNuxDefaultsKey: true } })
detox[54371] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [exec.js/EXEC_CMD, #10] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/ExpoDetoxHook/ios/d49fa2ddb665bfbaeb7e286b34efc73912f59c66/ExpoDetoxHook.framework/ExpoDetoxHook:/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:58963" -detoxSessionId "e36ef041-2bde-00df-d586-44b10a2a6098" -EXKernelDisableNuxDefaultsKey "true"
detox[54371] DEBUG: [exec.js/EXEC_TRY, #10] Launching host.exp.Exponent...
detox[54371] TRACE: [exec.js/EXEC_SUCCESS, #10] host.exp.Exponent: 54511

detox[54371] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[54511] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:58963',
     detoxSessionId: 'e36ef041-2bde-00df-d586-44b10a2a6098',
     EXKernelDisableNuxDefaultsKey: true },
  pid: 54511 })
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=testee action=ready (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"ready","messageId":-1000,"params":{}}
 
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"waitForActive","params":{},"messageId":2}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=waitForActive (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=testee action=waitForActiveDone (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"waitForActiveDone","messageId":2,"params":{}}
 
  console.log e2e/firstTest.spec.js:20
    Opening app URL: exp://192.168.86.24:19004

detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"deliverPayload","params":{"url":"exp://192.168.86.24:19004"},"messageId":3}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=deliverPayload (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
Example: should open the app URL [FAIL]

detox[54371] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should open the app URL"
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({ title: 'should open the app URL',
  fullName: 'Example should open the app URL',
  status: 'failed' })
detox[54371] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterAll()
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"cleanup","params":{"stopRunner":true},"messageId":4}
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=tester action=cleanup (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [DetoxServer.js/MESSAGE] role=testee action=cleanupDone (sessionId=e36ef041-2bde-00df-d586-44b10a2a6098)
detox[54371] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"cleanupDone","messageId":4,"params":{}}
 
 FAIL  e2e/firstTest.spec.js (258.305s)
  Example
    ✕ should load the app (120243ms)
    ✕ should open the app URL (120003ms)

  ● Example › should load the app

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

       8 |     console.log("App launched")
       9 |     await expect(element(by.text('Open up App.js to start working on your app!'))).toBeVisible();
    > 10 |   });
         |   ^
      11 | 
      12 |  it('should open the app URL', async () => {
      13 |     console.log("Lauching expo")

      at new Spec (../node_modules/@jest/core/node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (firstTest.spec.js:10:3)
      at Object.<anonymous> (firstTest.spec.js:9:1)

  ● Example › should open the app URL

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



      at new Spec (../node_modules/@jest/core/node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (firstTest.spec.js:31:3)
      at Object.<anonymous> (firstTest.spec.js:9:1)

detox[54371] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54371] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=e36ef041-2bde-00df-d586-44b10a2a6098
detox[54369] ERROR: [cli.js] Error: Command failed: node_modules/.bin/jest --config=e2e/config.json --maxWorkers=1 '--testNamePattern=^((?!:android:).)*$' "e2e"

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 3, 2019

Please enable debug synchronization and post the log here. Thanks

@jeromecornet
Copy link
Author

Here you go (sorry I had posted the wrong log in another comment I deleted):

detox[8861] INFO:  [test.js] configuration="ios" loglevel="trace" debugSynchronization=3000 artifactsLocation="artifacts/ios.2019-06-03 12-06-32Z" recordLogs="none" takeScreenshots="manual" recordVideos="none" recordPerformance="none" reportSpecs=true node_modules/.bin/jest --config=e2e/config.json --maxWorkers=1 '--testNamePattern=^((?!:android:).)*$' "e2e"
detox[8865] INFO:  [DetoxServer.js] server listening on localhost:56660...
detox[8865] DEBUG: [AsyncWebSocket.js/WEBSOCKET_OPEN] opened web socket to: ws://localhost:56660
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"login","params":{"sessionId":"cc780e32-5ea3-3f86-ac51-8967cfa7b16a","role":"tester"},"messageId":0}
detox[8865] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"loginSuccess","params":{"sessionId":"cc780e32-5ea3-3f86-ac51-8967cfa7b16a","role":"tester"},"messageId":0}
 
detox[8865] DEBUG: [exec.js/EXEC_CMD, #0] /usr/bin/xcrun simctl list -j

8< - - - - - -
skipping long list of simulators
8< - - - -
detox[8865] DEBUG: [exec.js/EXEC_CMD, #1] applesimutils --list --byType "iPhone 8" --byOS "12.2"
detox[8865] DEBUG: [exec.js/EXEC_TRY, #1] Searching for device matching iPhone 8...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #1] [
  {
    "availabilityError" : "",
    "os" : {
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/Runtimes\/iOS.simruntime",
      "availabilityError" : "",
      "buildversion" : "16E226",
      "availability" : "(available)",
      "isAvailable" : true,
      "identifier" : "com.apple.CoreSimulator.SimRuntime.iOS-12-2",
      "version" : "12.2",
      "name" : "iOS 12.2"
    },
    "availability" : "(available)",
    "deviceType" : {
      "name" : "iPhone 8",
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/DeviceTypes\/iPhone 8.simdevicetype",
      "identifier" : "com.apple.CoreSimulator.SimDeviceType.iPhone-8"
    },
    "udid" : "2F0E2EDF-A080-4757-90C4-976F1445D7C4",
    "isAvailable" : true,
    "state" : "Booted",
    "name" : "iPhone 8"
  }
]

detox[8865] DEBUG: [exec.js/EXEC_CMD, #2] applesimutils --list --byId "2F0E2EDF-A080-4757-90C4-976F1445D7C4"
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #2] [
  {
    "availabilityError" : "",
    "os" : {
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/Runtimes\/iOS.simruntime",
      "availabilityError" : "",
      "buildversion" : "16E226",
      "availability" : "(available)",
      "isAvailable" : true,
      "identifier" : "com.apple.CoreSimulator.SimRuntime.iOS-12-2",
      "version" : "12.2",
      "name" : "iOS 12.2"
    },
    "availability" : "(available)",
    "deviceType" : {
      "name" : "iPhone 8",
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/DeviceTypes\/iPhone 8.simdevicetype",
      "identifier" : "com.apple.CoreSimulator.SimDeviceType.iPhone-8"
    },
    "udid" : "2F0E2EDF-A080-4757-90C4-976F1445D7C4",
    "isAvailable" : true,
    "state" : "Booted",
    "name" : "iPhone 8"
  }
]

detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBootDevice({ coldBoot: false,
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4' })
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeUninstallApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[8865] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[8865] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #3] 
detox[8865] DEBUG: [exec.js/EXEC_SUCCESS, #3] host.exp.Exponent uninstalled
detox[8865] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install 2F0E2EDF-A080-4757-90C4-976F1445D7C4 "/Users/jeromecornet/src/expotest/bin/expo.app"
detox[8865] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/jeromecornet/src/expotest/bin/expo.app...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #4] 
detox[8865] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/jeromecornet/src/expotest/bin/expo.app installed
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[8865] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[8865] DEBUG: [exec.js/EXEC_TRY, #5] Terminating host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #5] 
detox[8865] DEBUG: [exec.js/EXEC_SUCCESS, #5] host.exp.Exponent terminated
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a' } })
detox[8865] DEBUG: [exec.js/EXEC_CMD, #6] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:56660" -detoxSessionId "cc780e32-5ea3-3f86-ac51-8967cfa7b16a"
detox[8865] DEBUG: [exec.js/EXEC_TRY, #6] Launching host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #6] host.exp.Exponent: 8937

detox[8865] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[8937] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a' },
  pid: 8937 })
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=testee action=ready (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"ready","messageId":-1000,"params":{}}
 
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"waitForActive","params":{},"messageId":1}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=waitForActive (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=testee action=waitForActiveDone (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"waitForActiveDone","messageId":1,"params":{}}
 
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeAll()
Example: should load the app
detox[8865] TRACE: [Detox.js/DETOX_BEFORE_EACH] running test: "Example should load the app"
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeEach({ title: 'should load the app',
  fullName: 'Example should load the app',
  status: 'running' })
  console.log e2e/firstTest.spec.js:6
    Lauching using reloadApp

detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[8865] DEBUG: [exec.js/EXEC_CMD, #7] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[8865] DEBUG: [exec.js/EXEC_TRY, #7] Terminating host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #7] 
detox[8865] DEBUG: [exec.js/EXEC_SUCCESS, #7] host.exp.Exponent terminated
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a',
     EXKernelDisableNuxDefaultsKey: true,
     detoxURLBlacklistRegex:
      '\\("http://192.168.86.24:19001/onchange","https://e.crashlytics.com/spi/v2/events"\\)',
     detoxURLOverride: 'exp://192.168.86.24:19000',
     detoxSourceAppOverride: 'host.exp.exponent' } })
detox[8865] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [exec.js/EXEC_CMD, #8] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/ExpoDetoxHook/ios/d49fa2ddb665bfbaeb7e286b34efc73912f59c66/ExpoDetoxHook.framework/ExpoDetoxHook:/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:56660" -detoxSessionId "cc780e32-5ea3-3f86-ac51-8967cfa7b16a" -EXKernelDisableNuxDefaultsKey "true" -detoxURLBlacklistRegex "\("http://192.168.86.24:19001/onchange","https://e.crashlytics.com/spi/v2/events"\)" -detoxURLOverride "exp://192.168.86.24:19000" -detoxSourceAppOverride "host.exp.exponent"
detox[8865] DEBUG: [exec.js/EXEC_TRY, #8] Launching host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #8] host.exp.Exponent: 8964

detox[8865] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[8964] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a',
     EXKernelDisableNuxDefaultsKey: true,
     detoxURLBlacklistRegex:
      '\\("http://192.168.86.24:19001/onchange","https://e.crashlytics.com/spi/v2/events"\\)',
     detoxURLOverride: 'exp://192.168.86.24:19000',
     detoxSourceAppOverride: 'host.exp.exponent' },
  pid: 8964 })
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
Example: should load the app [FAIL]
Example: should open the app URL
detox[8865] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should load the app"
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({ title: 'should load the app',
  fullName: 'Example should load the app',
  status: 'failed' })
detox[8865] TRACE: [Detox.js/DETOX_BEFORE_EACH] running test: "Example should open the app URL"
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeEach({ title: 'should open the app URL',
  fullName: 'Example should open the app URL',
  status: 'running' })
  console.log e2e/firstTest.spec.js:13
    Lauching expo

detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({ deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  bundleId: 'host.exp.Exponent' })
detox[8865] DEBUG: [exec.js/EXEC_CMD, #9] /usr/bin/xcrun simctl terminate 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent
detox[8865] DEBUG: [exec.js/EXEC_TRY, #9] Terminating host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #9] 
detox[8865] DEBUG: [exec.js/EXEC_SUCCESS, #9] host.exp.Exponent terminated
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a',
     EXKernelDisableNuxDefaultsKey: true } })
detox[8865] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [exec.js/EXEC_CMD, #10] /bin/cat /dev/null >/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.out 2>/Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.err && SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/jeromecornet/Library/ExpoDetoxHook/ios/d49fa2ddb665bfbaeb7e286b34efc73912f59c66/ExpoDetoxHook.framework/ExpoDetoxHook:/Users/jeromecornet/Library/Detox/ios/0f0da01849237f5e3552f9c24f9315745fb4c726/Detox.framework/Detox" /usr/bin/xcrun simctl launch --stdout=/tmp/detox.last_launch_app_log.out --stderr=/tmp/detox.last_launch_app_log.err 2F0E2EDF-A080-4757-90C4-976F1445D7C4 host.exp.Exponent --args -detoxServer "ws://localhost:56660" -detoxSessionId "cc780e32-5ea3-3f86-ac51-8967cfa7b16a" -EXKernelDisableNuxDefaultsKey "true"
detox[8865] DEBUG: [exec.js/EXEC_TRY, #10] Launching host.exp.Exponent...
detox[8865] TRACE: [exec.js/EXEC_SUCCESS, #10] host.exp.Exponent: 9057

detox[8865] INFO:  [AppleSimUtils.js] host.exp.Exponent launched. The stdout and stderr logs were recreated, you can watch them with:
        tail -F /Users/jeromecornet/Library/Developer/CoreSimulator/Devices/2F0E2EDF-A080-4757-90C4-976F1445D7C4/data/tmp/detox.last_launch_app_log.{out,err}
detox[9057] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'host.exp.Exponent',
  deviceId: '2F0E2EDF-A080-4757-90C4-976F1445D7C4',
  launchArgs:
   { detoxServer: 'ws://localhost:56660',
     detoxSessionId: 'cc780e32-5ea3-3f86-ac51-8967cfa7b16a',
     EXKernelDisableNuxDefaultsKey: true },
  pid: 9057 })
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=testee action=ready (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"ready","messageId":-1000,"params":{}}
 
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"waitForActive","params":{},"messageId":2}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=waitForActive (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=testee action=waitForActiveDone (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"waitForActiveDone","messageId":2,"params":{}}
 
  console.log e2e/firstTest.spec.js:20
    Opening app URL: exp://192.168.86.24:19000

detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"deliverPayload","params":{"url":"exp://192.168.86.24:19000"},"messageId":3}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=deliverPayload (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
Example: should open the app URL [FAIL]

detox[8865] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should open the app URL"
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({ title: 'should open the app URL',
  fullName: 'Example should open the app URL',
  status: 'failed' })
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterAll()
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"cleanup","params":{"stopRunner":true},"messageId":4}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=cleanup (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=testee action=cleanupDone (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"cleanupDone","messageId":4,"params":{}}
 
 FAIL  e2e/firstTest.spec.js (259.191s)
  Example
    ✕ should load the app (120445ms)
    ✕ should open the app URL (120002ms)

  ● Example › should load the app

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

       8 |     console.log("App launched")
       9 |     await expect(element(by.text('Open up App.js to start working on your app!'))).toBeVisible();
    > 10 |   });
         |   ^
      11 | 
      12 |  it('should open the app URL', async () => {
      13 |     console.log("Lauching expo")

      at new Spec (../node_modules/@jest/core/node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (firstTest.spec.js:10:3)
      at Object.<anonymous> (firstTest.spec.js:9:1)

  ● Example › should open the app URL

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



      at new Spec (../node_modules/@jest/core/node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Suite.<anonymous> (firstTest.spec.js:31:3)
      at Object.<anonymous> (firstTest.spec.js:9:1)

detox[8865] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8865] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a
detox[8861] ERROR: [cli.js] Error: Command failed: node_modules/.bin/jest --config=e2e/config.json --maxWorkers=1 '--testNamePattern=^((?!:android:).)*$' "e2e"

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 3, 2019

detox[8865] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"deliverPayload","params":{"url":"exp://192.168.86.24:19000"},"messageId":3}
detox[8865] TRACE: [DetoxServer.js/MESSAGE] role=tester action=deliverPayload (sessionId=cc780e32-5ea3-3f86-ac51-8967cfa7b16a)
Example: should open the app URL [FAIL]

detox[8865] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should open the app URL"
detox[8865] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({ title: 'should open the app URL',
  fullName: 'Example should open the app URL',
  status: 'failed' })

I see from the log that you are trying to use openURL and then your test fails. But I don't see any sync blocks. So it's something on your end. The app seems idle.

@jeromecornet
Copy link
Author

Thanks for looking into it @LeoNatan.
What I don't understand is that both scenarios fail (not just openUrl):

  • reloadApp() which calls device.launchApp({ url, ...others})
  • device.launchApp({...others}), then device.openUrl({url})

The project was just created with expo init and displays the welcome screen, so there is no real code that can fail at that level. When you say 'something on your end' do you mean the expo client ? or the tests themselves ?

@jeromecornet
Copy link
Author

Also (this may be useful info) I have no problem using detox on the standalone built app that is generated from that project, only when trying to use detox with the expo client itself.

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 3, 2019

My guess would be the tests, since I don't see the app being stuck in sync issues...

@jeromecornet
Copy link
Author

Mhhh, I'm not sure what part of the test it could be:
the init.js file is straight out of detox init -r jest and

If you look at that repo https://github.com/jeromecornet/expotest, it's just after running expo init then detox init and making a test that calls reloadApp.
Is there something missing in the setup of the test ? If so that probably should be added to detox init

Rather than a bug in the test, it looks to me like the the websocket send call in Client.js#sendAction (which ultimately gets called in both situations) does not resolve.

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 4, 2019

I am sorry, I am not familiar with expo at all. But it seems like the app is running, and I don't see anything in the log that shows me that detox is stuck in sync. Could you maybe set the sync print to something like 200 rather than 3000? But again, 3000 should still be enough to see if it is stuck.

@tomas-petrovcin
Copy link

tomas-petrovcin commented Jun 4, 2019

It actually does the same in ejected app #1187

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 5, 2019

Sorry guys, I don’t know how to debug this. If someone is willing to step up and help, it would be greatly appreciated.

@brookemitchell
Copy link

Our detox with expo tests stopped working after detox 12.3.0. Thanks for the minimal example, I can try and confirm tomorrow and offer something useful or confirm

@aarshaw
Copy link

aarshaw commented Jun 10, 2019

Was anyone able to find a workaround for this? or a version of detox where it works?

@bladey
Copy link

bladey commented Jun 13, 2019

Confirming 12.3.0 fixes the issue for me, don't have any solutions at this time.

@jmporchet
Copy link

jmporchet commented Jun 21, 2019

Confirming 12.3.0 fixes the issue for me, don't have any solutions at this time.

You mean downgrading to 12.3.0 makes the issue go away? should have read better
I can still reproduce this bug on 12.11.0 myself. Still have to test with 12.11.1, but based on the commits since then I'not expecting this to work.

@yaron1m
Copy link
Contributor

yaron1m commented Jun 22, 2019

This also happens to me - Expo only works with detox 12.3.0.
I made a sample project - this may help who ever is trying to solve this (@LeoNatan):
https://github.com/yaron1m/expo-detox-typescript-example

@LeoNatan
Copy link
Contributor

Please use the new debug option documented here to see why Detox hangs on launch.

Add the -detoxPrintBusyIdleResources YES launch argument.
Then use xcrun simctl spawn booted log stream --level debug --style compact --predicate "category=='EarlGreyStatistics'" to get the specific log entries.

@jeromecornet
Copy link
Author

Thanks @LeoNatan
That log was massive so I removed consecutive duplicate lines

Here's what I got:

2019-06-28 10:43:12.942 Db Exponent[94847:271f1c] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.apple.main-thread
2019-06-28 10:43:30.188 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timed -> busy animateWithDuration:delay:options:animations:completion:
2019-06-28 10:43:30.217 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:30.585 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timer -> busy Tracking Timer <__NSCFTimer: 0x600000c049c0>
2019-06-28 10:43:30.691 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timer -> busy Tracking Timer <__NSCFTimer: 0x600000c1b000>
2019-06-28 10:43:30.738 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.facebook.react.BlobModuleQueue
2019-06-28 10:43:30.738 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timer -> busy Tracking Timer <__NSCFTimer: 0x600000c1b000>
2019-06-28 10:43:30.852 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.facebook.react.KeyboardObserverQueue
2019-06-28 10:43:30.852 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timer -> busy Tracking Timer <__NSCFTimer: 0x600000c1b000>
2019-06-28 10:43:30.965 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timed -> busy animateWithDuration:animations:completion:
2019-06-28 10:43:30.973 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.apple.NSURLSession-work
2019-06-28 10:43:31.004 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timed -> busy animateWithDuration:delay:options:animations:completion:
2019-06-28 10:43:31.181 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.facebook.react.FileReaderModuleQueue
2019-06-28 10:43:31.181 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timed -> busy animateWithDuration:delay:options:animations:completion:
2019-06-28 10:43:32.009 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Timer -> busy IdlingResource For Timer <__NSCFTimer: 0x600000c38f00>
2019-06-28 10:43:33.342 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:33.342 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:33.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:33.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:35.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:35.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:35.377 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:35.377 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:37.343 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:37.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:39.352 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:39.352 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:39.378 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:39.378 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:41.315 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:41.315 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:41.343 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:41.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:43.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:43.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:43.361 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:43.361 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:44.984 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.apple.NSURLSession-work
2019-06-28 10:43:44.984 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:45.103 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] Dispatch Queue -> busy com.apple.NSURLSession-work
2019-06-28 10:43:45.106 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:45.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:45.353 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:45.363 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:45.363 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:47.354 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:47.354 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:47.380 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:47.380 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:49.354 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:49.354 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:53.356 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:53.356 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:55.346 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:55.356 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.
2019-06-28 10:43:55.380 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] WXRunLoopIdlingResource -> busy React Native thread is busy.
2019-06-28 10:43:55.380 Db Exponent[95085:272499] [com.wix.Detox:EarlGreyStatistics] ReactNative JS Loading -> busy React Native is loading Javascript.

The output of detox test shows

detox[94950] WARN:  [Client.js/PENDING_REQUESTS] App has not responded to the network requests below:
  (id = -1000) isReady: {}

That might be the reason why the test "Example should load the app with the url" has timed out.

So it looks like it's not detecting that the app has finished loading.

Now on the other hand, I managed to find a workaround: launch expo without any app, set the live reload blacklist then call device.openURL
This test is now passing:
https://github.com/jeromecornet/expotest/blob/b09b2b65ed007fdacb1a3a88150452694d189616/e2e/firstTest.spec.js#L31-L47
(although this specific version uses detoxPrintBusyIdleResources: 'YES' which you don't need)

In my prior tests, the device.openURL would fail because I did not specify the Blacklist for live reload and it got stuck waiting for the /onchange call to be dealt with (which I discovered using the EarlGreyStatistics)

@LeoNatan
Copy link
Contributor

Hm, it seems the load operation is not ending and that's why it's stuck. Could be that Expo is using some RN configuration or load type that we are not familiar with.

Not sure what you mean in your workaround, but I guess it's good that it exists.

Unfortunately, as I said, I don't have the resources to debug Expo. If someone can reproduce the same loading behavior in an empty example project, I'll take a look. If someone is willing to debug this issue, I'll provide assistance.

@LeoNatan LeoNatan changed the title ios: Detox + Expo + jest : timeout on opening the app Detox + Expo + jest : timeout on opening the app Jun 30, 2019
@robertying

This comment has been minimized.

@LeoNatan

This comment has been minimized.

@robertying

This comment has been minimized.

@LeoNatan

This comment has been minimized.

@robertying

This comment has been minimized.

@LeoNatan

This comment has been minimized.

@robertying

This comment has been minimized.

@LeoNatan

This comment has been minimized.

@robertying

This comment has been minimized.

@robertying

This comment has been minimized.

@LeoNatan
Copy link
Contributor

LeoNatan commented Jun 30, 2019

Please use StackOverflow for general usage questions. This question is specifically about Expo.

@wolverineks
Copy link

@jeromecornet since git bisect is out of the question, how are you debugging?

@jeromecornet
Copy link
Author

@wolverineks I haven't debugged the issue besides running the few commands manually (see the linked repo with the test case to reproduce the problem).
git bisect would be ideal to find the commit that introduced the regression though.

@brookemitchell
Copy link

brookemitchell commented Jul 16, 2019

I've tried debugging this a little, all I know so far is that when you load a detox application (ie detox-expo-helpers:reloadApp calls device.launchApp and the actual expo app boots), the isReady message doesn't seem to get a response.

detox[94950] WARN:  [Client.js/PENDING_REQUESTS] App has not responded to the network requests below:
  (id = -1000) isReady: {}

I think the issue can be fixed in https://github.com/expo/detox-tools/tree/master/packages/expo-detox-hook by making sure the test runtime notifies detox server the app is ready correctly? I'm guessing a little here.

I'll try the 'launch expo without any app, set the live reload blacklist then call device.openURL' workaround @jeromecornet suggested (thanks for the help) (nah it was something else, see next comment)

@brookemitchell
Copy link

brookemitchell commented Jul 28, 2019

Well think I found the offending commit 32be293

Reverting this commit works for me with the latest detox, can any other expo users confirm?

I think that change broke passing in a url blacklist on launch?

From the detox docs for device-launch

It seems after the commit passing a blacklistregex to launchArgs like

{ detoxURLBlacklistRegex: '\\("http://192.168.1.253:19001/onchange","https://e.crashlytics.com/spi/v2/events"\\)'}

(see: detox-expo-helper#L105) to DetoxManager.m no longer works? Sorry I don't have the obj-c debugging chops to be certain right now.

@xcarpentier
Copy link
Contributor

xcarpentier commented Jul 29, 2019

Hi @brookemitchell
I confirm because I'm using this patch and my e2e tests was fix detox+13.3.1.patch:

diff --git a/node_modules/detox/src/devices/ios/AppleSimUtils.js b/node_modules/detox/src/devices/ios/AppleSimUtils.js
index 72b8d3a..391930e 100644
--- a/node_modules/detox/src/devices/ios/AppleSimUtils.js
+++ b/node_modules/detox/src/devices/ios/AppleSimUtils.js
@@ -280,7 +280,7 @@ class AppleSimUtils {
   }
 
   _joinLaunchArgs(launchArgs) {
-    return _.map(launchArgs, (v, k) => `-${k} "${v}"`).join(' ').trim();
+    return _.map(launchArgs, (v, k) => `-${k} ${v}`).join(' ').trim();
   }
 
   async _launchMagically(frameworkPath, udid, bundleId, launchArgs, languageAndLocale) {

@brookemitchell
Copy link

Thanks I'm applying the same patch for now (😄 patch-package). I know the double quote->arguments map fixed an issue with url argument splitting (see: #1294).

Maybe the more comprehensive fix is to look at how detoxURLBlacklistRegex is made. Passing a regex argument like this doesn't feel the most intuitive. Maybe it could be a regex list idk

@maitriyogin
Copy link

Hi, this certainly fixes the issue so huge thanks!
Was wondering if anyones created a PN for this?
Cheers,
Stephen.

@brookemitchell
Copy link

@maitriyogin Not yet, it's one of those cases where a change solved the issue for another use case (multiple argument urls).

Solution is to write tests for both use cases and fix it, just haven't had the time yet.

@LeoNatan
Copy link
Contributor

According with our statement here, I am closing this issue. General Expo questions are no longer allowed. Please follow these issues with the Expo team or in the Expo community. Thanks!

@lock lock bot locked as resolved and limited conversation to collaborators Sep 1, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests