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

Timeout on ejected expo project #1627

Closed
1 task done
clems36 opened this issue Aug 26, 2019 · 10 comments
Closed
1 task done

Timeout on ejected expo project #1627

clems36 opened this issue Aug 26, 2019 · 10 comments

Comments

@clems36
Copy link

clems36 commented Aug 26, 2019

Describe the bug
detox test reaches the timeout and returns ReferenceError: device is not defined and ReferenceError: element is not defined.

The issue comes from line 126 of Client.js:

const response = await this.ws.send(action, action.messageId);

When action = Ready { type: 'isReady', params: {}, messageId: -1000 }, response is never returned and jest times out.
I know this issue has been reported by a few other people already (#1288, #908, #155, #917, ...) but all of these are dead ends for ejected expo projects.

Important detail: the only way i've made this work is by running detox with the release configuration, but i want to make it work with the debug config as showed in the "Getting started" guide.

To Reproduce

  • I have tested this issue on the latest Detox release and it still reproduces
  1. Make sure you have the latest version of expo-cli by running npm install expo-cli -g
  2. Run expo init to create a new project
  3. cd into your project, run yarn && cd ios && pod install
  4. Follow the steps to configure detox
  5. Inside package.json, change the binaryPath of your app if needed
  6. Run detox build and detox test

Expected behavior
detox.init() should not hang when sending the "Ready" action.

Environment:

  • Detox: 14.0.3
  • React Native: 0.59.8
  • Node: v12.9.0
  • Device: ios simulator, any model
  • Xcode: 10.3
  • iOS: 12.4
  • macOS: Mojave 10.14.6

Device and Verbose Detox Logs
These are the last logs before the tests fail:

detox[43453] INFO:  [AppleSimUtils.js] com.detox.test launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 6A559B40-4542-419A-86CE-F60C6EDE7AD4 log stream --level debug --style compact --predicate 'processImagePath beginsWith "/Users/clementdebellefroid/Library/Developer/CoreSimulator/Devices/6A559B40-4542-419A-86CE-F60C6EDE7AD4/data/Containers/Bundle/Application/8E103AE9-3438-4952-94B9-9823F803DB2B/detox-test.app"'
detox[43485] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({
  bundleId: 'com.detox.test',
  deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4',
  launchArgs: {
    detoxServer: 'ws://localhost:53448',
    detoxSessionId: 'f156d72d-25b5-a3c6-70bf-b17b5fddce44'
  },
  pid: 43485
})
detox[43453] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[43453] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=f156d72d-25b5-a3c6-70bf-b17b5fddce44)
detox[43453] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=f156d72d-25b5-a3c6-70bf-b17b5fddce44)
detox[43453] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=f156d72d-25b5-a3c6-70bf-b17b5fddce44
detox[43453] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=f156d72d-25b5-a3c6-70bf-b17b5fddce44

I'm super eager to try detox, i'm just a few steps away from it. Any help is welcome!

@LeoNatan
Copy link
Contributor

What is new here in this issue that isn't available in the previous ones? What does "dead ends for ejected expo projects" mean?

@clems36
Copy link
Author

clems36 commented Aug 27, 2019

Either the resolved ones are bare react-native projects/non-ejected Expo projects or there is no answer to the original question: why is there no response from the WebSocket when the "Ready" action is sent ?

@LeoNatan
Copy link
Contributor

Have you used the appropriate debugging docs to try and track down why the sync is stuck?

@LeoNatan
Copy link
Contributor

Perhaps it is a similar issue to #1422 regardless of ejection status. Follow the sync debugging docs, report here with findings and we'll see.

@clems36
Copy link
Author

clems36 commented Aug 27, 2019

Running detox test -c ios.sim.debug -l trace -d 10000 gives me this before timing out (i've cut the beginning of the logs):

detox[55869] DEBUG: [exec.js/EXEC_CMD, #1] applesimutils --list --byType "iPhone 7" --byOS "12.4"
detox[55869] DEBUG: [exec.js/EXEC_TRY, #1] Searching for device matching iPhone 7...
detox[55869] 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" : "16G73",
      "availability" : "(available)",
      "isAvailable" : true,
      "identifier" : "com.apple.CoreSimulator.SimRuntime.iOS-12-4",
      "version" : "12.4",
      "name" : "iOS 12.4"
    },
    "availability" : "(available)",
    "deviceType" : {
      "name" : "iPhone 7",
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/DeviceTypes\/iPhone 7.simdevicetype",
      "identifier" : "com.apple.CoreSimulator.SimDeviceType.iPhone-7"
    },
    "udid" : "6A559B40-4542-419A-86CE-F60C6EDE7AD4",
    "isAvailable" : true,
    "state" : "Booted",
    "name" : "iPhone 7"
  }
]

detox[55869] DEBUG: [exec.js/EXEC_CMD, #2] applesimutils --list --byId "6A559B40-4542-419A-86CE-F60C6EDE7AD4"
detox[55869] 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" : "16G73",
      "availability" : "(available)",
      "isAvailable" : true,
      "identifier" : "com.apple.CoreSimulator.SimRuntime.iOS-12-4",
      "version" : "12.4",
      "name" : "iOS 12.4"
    },
    "availability" : "(available)",
    "deviceType" : {
      "name" : "iPhone 7",
      "bundlePath" : "\/Applications\/Xcode.app\/Contents\/Developer\/Platforms\/iPhoneOS.platform\/Developer\/Library\/CoreSimulator\/Profiles\/DeviceTypes\/iPhone 7.simdevicetype",
      "identifier" : "com.apple.CoreSimulator.SimDeviceType.iPhone-7"
    },
    "udid" : "6A559B40-4542-419A-86CE-F60C6EDE7AD4",
    "isAvailable" : true,
    "state" : "Booted",
    "name" : "iPhone 7"
  }
]

detox[55869] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBootDevice({ coldBoot: false, deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4' })
detox[55869] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeUninstallApp({
  deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4',
  bundleId: 'com.detox.test'
})
detox[55869] DEBUG: [exec.js/EXEC_CMD, #3] /usr/bin/xcrun simctl uninstall 6A559B40-4542-419A-86CE-F60C6EDE7AD4 com.detox.test
detox[55869] DEBUG: [exec.js/EXEC_TRY, #3] Uninstalling com.detox.test...
detox[55869] TRACE: [exec.js/EXEC_SUCCESS, #3]
detox[55869] DEBUG: [exec.js/EXEC_SUCCESS, #3] com.detox.test uninstalled
detox[55869] DEBUG: [exec.js/EXEC_CMD, #4] /usr/bin/xcrun simctl install 6A559B40-4542-419A-86CE-F60C6EDE7AD4 "/Users/clementdebellefroid/Library/Developer/Xcode/DerivedData/detox-test-bdznjcaewoobdcfdwtdisdwidhjo/Build/Products/Debug-iphonesimulator/detox-test.app"
detox[55869] DEBUG: [exec.js/EXEC_TRY, #4] Installing /Users/clementdebellefroid/Library/Developer/Xcode/DerivedData/detox-test-bdznjcaewoobdcfdwtdisdwidhjo/Build/Products/Debug-iphonesimulator/detox-test.app...
detox[55869] TRACE: [exec.js/EXEC_SUCCESS, #4]
detox[55869] DEBUG: [exec.js/EXEC_SUCCESS, #4] /Users/clementdebellefroid/Library/Developer/Xcode/DerivedData/detox-test-bdznjcaewoobdcfdwtdisdwidhjo/Build/Products/Debug-iphonesimulator/detox-test.app installed
detox[55869] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeTerminateApp({
  deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4',
  bundleId: 'com.detox.test'
})
detox[55869] DEBUG: [exec.js/EXEC_CMD, #5] /usr/bin/xcrun simctl terminate 6A559B40-4542-419A-86CE-F60C6EDE7AD4 com.detox.test
detox[55869] DEBUG: [exec.js/EXEC_TRY, #5] Terminating com.detox.test...
detox[55869] TRACE: [exec.js/EXEC_SUCCESS, #5]
detox[55869] DEBUG: [exec.js/EXEC_SUCCESS, #5] com.detox.test terminated
detox[55869] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeLaunchApp({
  bundleId: 'com.detox.test',
  deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4',
  launchArgs: {
    detoxServer: 'ws://localhost:58521',
    detoxSessionId: '9bfba9d5-7a49-5145-2854-7f89f398ce76'
  }
})
detox[55869] DEBUG: [exec.js/EXEC_CMD, #6] SIMCTL_CHILD_DYLD_INSERT_LIBRARIES="/Users/clementdebellefroid/Library/Detox/ios/9438597daf71372b4cbcf71962463a77cd7c7c33/Detox.framework/Detox" /usr/bin/xcrun simctl launch 6A559B40-4542-419A-86CE-F60C6EDE7AD4 com.detox.test --args -detoxServer "ws://localhost:58521" -detoxSessionId "9bfba9d5-7a49-5145-2854-7f89f398ce76"
detox[55869] DEBUG: [exec.js/EXEC_TRY, #6] Launching com.detox.test...
detox[55869] TRACE: [exec.js/EXEC_SUCCESS, #6] com.detox.test: 55901

detox[55869] DEBUG: [exec.js/EXEC_CMD, #7] /usr/bin/xcrun simctl get_app_container 6A559B40-4542-419A-86CE-F60C6EDE7AD4 com.detox.test
detox[55869] TRACE: [exec.js/EXEC_SUCCESS, #7] /Users/clementdebellefroid/Library/Developer/CoreSimulator/Devices/6A559B40-4542-419A-86CE-F60C6EDE7AD4/data/Containers/Bundle/Application/B43AA86A-7D26-4024-A05C-DB88EC6D9FB5/detox-test.app

detox[55869] INFO:  [AppleSimUtils.js] com.detox.test launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 6A559B40-4542-419A-86CE-F60C6EDE7AD4 log stream --level debug --style compact --predicate 'processImagePath beginsWith "/Users/clementdebellefroid/Library/Developer/CoreSimulator/Devices/6A559B40-4542-419A-86CE-F60C6EDE7AD4/data/Containers/Bundle/Application/B43AA86A-7D26-4024-A05C-DB88EC6D9FB5/detox-test.app"'
detox[55901] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({
  bundleId: 'com.detox.test',
  deviceId: '6A559B40-4542-419A-86CE-F60C6EDE7AD4',
  launchArgs: {
    detoxServer: 'ws://localhost:58521',
    detoxSessionId: '9bfba9d5-7a49-5145-2854-7f89f398ce76'
  },
  pid: 55901
})
detox[55869] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[55869] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=9bfba9d5-7a49-5145-2854-7f89f398ce76)
detox[55869] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=9bfba9d5-7a49-5145-2854-7f89f398ce76)
detox[55869] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=9bfba9d5-7a49-5145-2854-7f89f398ce76
detox[55869] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=9bfba9d5-7a49-5145-2854-7f89f398ce76

@LeoNatan
Copy link
Contributor

LeoNatan commented Aug 27, 2019

@clems36
Copy link
Author

clems36 commented Aug 27, 2019

detox test -c ios.sim.debug -l trace -d:

detox[56117] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":8}
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=testee action=currentStatusResult (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"currentStatusResult","messageId":8,"params":{"state":"busy","resources":[{"name":"App State","info":{"appState":"Waiting for network requests to finish.","urls":["http://10.4.12.46:19001/onchange"],"prettyPrint":"Waiting for network requests to finish.: (\n    \"http://10.4.12.46:19001/onchange\"\n)","elements":["LocalDataTask <DEF824C1-5604-4620-87A2-AEB904137079>.<2>"]}},{"name":"Dispatch Queue","info":{"queue":"<OS_dispatch_queue_main: com.apple.main-thread[0x11479da80] = { xref = -2147483648, ref = -2147483648, sref = 1, target = com.apple.root.default-qos.overcommit[0x11479df00], width = 0x1, state = 0x001ffe9000000300, dirty, in-flight = 0, thread = 0x303 }>","prettyPrint":"com.apple.main-thread"}}],"messageId":8}}

detox[56117] INFO:  [actions.js] Sync App State: Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
detox[56117] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":9}
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=testee action=currentStatusResult (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"currentStatusResult","messageId":9,"params":{"state":"busy","resources":[{"name":"App State","info":{"appState":"Waiting for network requests to finish.","urls":["http://10.4.12.46:19001/onchange"],"prettyPrint":"Waiting for network requests to finish.: (\n    \"http://10.4.12.46:19001/onchange\"\n)","elements":["LocalDataTask <DEF824C1-5604-4620-87A2-AEB904137079>.<2>"]}},{"name":"Dispatch Queue","info":{"queue":"<OS_dispatch_queue_main: com.apple.main-thread[0x11479da80] = { xref = -2147483648, ref = -2147483648, sref = 1, target = com.apple.root.default-qos.overcommit[0x11479df00], width = 0x1, state = 0x001ffe9000000300, dirty, in-flight = 0, thread = 0x303 }>","prettyPrint":"com.apple.main-thread"}}],"messageId":9}}

detox[56117] INFO:  [actions.js] Sync App State: Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
detox[56117] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":10}
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [DetoxServer.js/MESSAGE] role=testee action=currentStatusResult (sessionId=568d48bf-7ca8-dcbe-3d5c-25c7589ec937)
detox[56117] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"currentStatusResult","messageId":10,"params":{"state":"busy","resources":[{"name":"App State","info":{"appState":"Waiting for network requests to finish.","urls":["http://10.4.12.46:19001/onchange"],"prettyPrint":"Waiting for network requests to finish.: (\n    \"http://10.4.12.46:19001/onchange\"\n)","elements":["LocalDataTask <DEF824C1-5604-4620-87A2-AEB904137079>.<2>"]}},{"name":"Dispatch Queue","info":{"queue":"<OS_dispatch_queue_main: com.apple.main-thread[0x11479da80] = { xref = -2147483648, ref = -2147483648, sref = 1, target = com.apple.root.default-qos.overcommit[0x11479df00], width = 0x1, state = 0x001ffe9000000300, dirty, in-flight = 0, thread = 0x303 }>","prettyPrint":"com.apple.main-thread"}}],"messageId":10}}

detox[56117] INFO:  [actions.js] Sync App State: Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
detox[56117] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread
Example: should have welcome screen [FAIL]
Example: should show hello screen after tap
detox[56117] TRACE: [Detox.js/DETOX_AFTER_EACH] failed test: "Example should have welcome screen"
detox[56117] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onAfterEach({
  title: 'should have welcome screen',
  fullName: 'Example should have welcome screen',
  status: 'failed',
  timedOut: true
})
detox[56117] WARN:  [Client.js/PENDING_REQUESTS] App has not responded to the network requests below:
  (id = 1) invoke: {"target":{"type":"Invocation","value":{"target":{"type":"EarlGrey","value":"instance"},"method":"detox_selectElementWithMatcher:","args":[{"type":"Invocation","value":{"target":{"type":"Class","value":"GREYMatchers"},"method":"matcherForAccessibilityID:","args":[{"type":"NSString","value":"welcome"}]}}]}},"method":"assertWithMatcher:","args":[{"type":"Invocation","value":{"target":{"type":"Class","value":"GREYMatchers"},"method":"matcherForSufficientlyVisible","args":[]}}]}
  (id = -1000) reactNativeReload: {}

That might be the reason why the test "Example should have welcome screen" has timed out.

detox[56117] TRACE: [Detox.js/DETOX_BEFORE_EACH] running test: "Example should show hello screen after tap"
detox[56117] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onBeforeEach({
  title: 'should show hello screen after tap',
  fullName: 'Example should show hello screen after tap',
  status: 'running'
})

xcrun simctl spawn booted log stream --level debug --style compact --predicate "category=='EarlGreyStatistics'":

2019-08-27 11:08:33.010 Db detox-test[56151:88e91] [com.wix.Detox:EarlGreyStatistics] App State -> busy Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
2019-08-27 11:08:33.010 Db detox-test[56151:88e91] [com.wix.Detox:EarlGreyStatistics] App State -> busy Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
2019-08-27 11:08:33.010 Db detox-test[56151:88e91] [com.wix.Detox:EarlGreyStatistics] App State -> busy Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)
2019-08-27 11:08:33.010 Db detox-test[56151:88e91] [com.wix.Detox:EarlGreyStatistics] App State -> busy Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)

@LeoNatan
Copy link
Contributor

OK, so you have your answer. It's your network requests that are causing the problem. Follow the docs to set this URL in a blacklist so it doesn't interfere with Detox.

@clems36
Copy link
Author

clems36 commented Aug 27, 2019

@LeoNatan I've tried device.setURLBlacklist and detoxURLBlacklistRegex (both separately and together):

beforeAll(async () => {
  await detox.init(config, { launchApp: false });
  await device.setURLBlacklist([".*10.4.12.46.*"]);
  await device.launchApp({
    newInstance: true,
    launchArgs: {
      detoxURLBlacklistRegex: '\\("http://10.4.12.46:19001/onchange"\\)'
    }
  });
});

but no luck, i'm still getting

detox[57099] WARN:  [Client.js/PENDING_REQUESTS] App has not responded to the network requests below:
  (id = 1) invoke: {"target":{"type":"Invocation","value":{"target":{"type":"Class","value":"GREYConfiguration"},"method":"sharedInstance","args":[]}},"method":"setValue:forConfigKey:","args":[["http://10.4.12.46:19001/onchange"],{"type":"NSString","value":"GREYConfigKeyURLBlacklistRegex"}]}
  (id = 3) invoke: {"target":{"type":"Invocation","value":{"target":{"type":"EarlGrey","value":"instance"},"method":"detox_selectElementWithMatcher:","args":[{"type":"Invocation","value":{"target":{"type":"Class","value":"GREYMatchers"},"method":"matcherForAccessibilityID:","args":[{"type":"NSString","value":"welcome"}]}}]}},"method":"assertWithMatcher:","args":[{"type":"Invocation","value":{"target":{"type":"Class","value":"GREYMatchers"},"method":"matcherForSufficientlyVisible","args":[]}}]}
  (id = -1000) reactNativeReload: {}

That might be the reason why the test "Example should have welcome screen" has timed out.

followed by

detox[57573] INFO:  [actions.js] Sync App State: Waiting for network requests to finish.: (
    "http://10.4.12.46:19001/onchange"
)

@clems36
Copy link
Author

clems36 commented Aug 27, 2019

I got it to work by disabling live reload after launching the app. Thanks for your help

@lock lock bot locked as resolved and limited conversation to collaborators Aug 30, 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

3 participants