detox doesn’t complete ‘launchApp’ when using a debug build

Description

  • if you use a debug build -with the js server running- the detox launchApp command hangs and the app is stuck on the splash screen

  • I can see from debug-synchronization that detox is waiting for the js bundle to finish loading but i can see from my other terminal that it has finished.

  • if I stop detox and force close and re-open the app the app launches without issue

  • If i pass launch args to blacklist the js bundle request i get a different error message which i can provide if that would be helpful

  • if i pass launch args to disable sync obviously the tests start to run too early (which might end up being the only work around)

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

Reproduction

Provide the steps necessary to reproduce the issue. If you are seeing a regression, try to provide the last known version where the issue did not reproduce.

  1. run detox build with the build script being react-native run-ios
  2. run detox test

Expected behavior

tests run as usual

Screenshots

N/A

Environment (please complete the following information):

  • Detox: 17.5.0 (but reproduced on all versions up to latest)
  • React Native: 0.63.2
  • Node:10.16.3
  • Device: simulator iPhone X
  • Xcode: 12.0.1
  • iOS: 14
  • macOS: 10.15.5

Logs

If you are experiencing a timeout in your test

see
2020-10-13 16:25:40.780 Db[15585:49bbee] [Test:EarlGreyStatistics] App State -> busy Waiting for network requests to finish: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)
2020-10-13 16:25:40.780 Db[15585:49bbee] [Test:EarlGreyStatistics] App State -> busy Waiting for network requests to finish: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)
2020-10-13 16:25:40.780 Db[15585:49bbee] [Test:EarlGreyStatistics] App State -> busy Waiting for network requests to finish: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)
2020-10-13 16:25:40.780 Db[15585:49bbee] [Test:EarlGreyStatistics] App State -> busy Waiting for network requests to finish: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)

If you are seeing a build problem (e.g. during npm install)

n/a

Device and verbose Detox logs

  • I have run my tests using the --loglevel trace argument and am providing the verbose log below:
see
detox[92948] DEBUG: [exec.js/EXEC_TRY, #6] Launching co.uk....
detox[92948] TRACE: [exec.js/EXEC_SUCCESS, #6] co.uk.: 93053

detox[92948] DEBUG: [exec.js/EXEC_CMD, #7] /usr/bin/xcrun simctl get_app_container 8A629C77-16CD-4AA0-BED9-6BA7314245BA co.uk.
detox[92948] TRACE: [exec.js/EXEC_SUCCESS, #7] /Users//Library/Developer/CoreSimulator/Devices/8A629C77-16CD-4AA0-BED9-6BA7314245BA/data/Containers/Bundle/Application/E8637298-00E0-4F57-830E-1FD2B5A8D938/.app

detox[92948] INFO:  [AppleSimUtils.js] co.uk.launched. To watch simulator logs, run:
        /usr/bin/xcrun simctl spawn 8A629C77-16CD-4AA0-BED9-6BA7314245BA log stream --level debug --style compact --predicate 'process == ""'
detox[93053] TRACE: [ArtifactsManager.js/LIFECYCLE] artifactsManager.onLaunchApp({ bundleId: 'co.uk.',
  deviceId: '8A629C77-16CD-4AA0-BED9-6BA7314245BA',
  launchArgs:
   { detoxServer: 'ws://localhost:52373',
     detoxSessionId: '097cb438-bccf-1dde-b297-09a210612fc5',
     detoxDisableHierarchyDump: true },
  pid: 93053 })
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"isReady","params":{},"messageId":-1000}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=isReady (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":1}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":2}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":3}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":4}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":5}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":6}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=097cb438-bccf-1dde-b297-09a210612fc5
detox[92948] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=097cb438-bccf-1dde-b297-09a210612fc5
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":7}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=testee action=currentStatusResult (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"currentStatusResult","params":{"resources":[{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:37 AM GMT+01:00","object":"<NSObject: 0x6000013cb560>","name":"animateWithDuration:animations:","prettyPrint":"animateWithDuration:animations:","duration":0.2}},{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(synchronizeToDisk) on APMPersistedConfig","prettyPrint":"performSelector @selector(synchronizeToDisk) on APMPersistedConfig","duration":2}},{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(synchronize) on APMUserDefaults","prettyPrint":"performSelector @selector(synchronize) on APMUserDefaults","duration":2}},{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication","prettyPrint":"performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication","duration":3}},{"name":"ReactNative JS Loading","info":{"prettyPrint":"React Native is loading Javascript."}},{"name":"App State","info":{"appState":"Waiting for view controller's view to appear\nWaiting for network requests to finish\nWaiting for window's root view controller's view to appear\nWaiting for view's draw or layout pass to complete","urls":["http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"],"prettyPrint":"Waiting for view controller's view to appear\nWaiting for network requests to finish\nWaiting for window's root view controller's view to appear\nWaiting for view's draw or layout pass to complete: (\n    \"http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false\"\n)","elements":["<_UIWindowTransformLayer: 0x60000177a1e0>","setNeedsDisplay: 0x7f8052366770 (HACK)","setNeedsDisplay: 0x7f8052366770 (HACK)","<UITransitionView: 0x7f805152edf0; frame = (0 0; 414 78); autoresize = W+H; layer = <CALayer: 0x60000174e980>>","setNeedsDisplay: 0x7f805236ab70 (HACK)","<UIViewController: 0x7f805236a4a0>","<UIView: 0x7f805152d670; frame = (0 0; 414 78); autoresize = W+H; layer = <CALayer: 0x60000174ea80>>","setNeedsDisplay: 0x7f8052324440 (HACK)","setNeedsDisplay: 0x7f8052366770 (HACK)","setNeedsDisplay: 0x7f80522127d0 (HACK)","setNeedsDisplay: 0x7f8052366770 (HACK)","<UIWindowLayer: 0x60000177a140>","<_UILabelLayer: 0x6000032c85f0>","setNeedsDisplay: 0x7f8052366770 (HACK)","<UIDropShadowView: 0x7f80522127d0; frame = (0 0; 414 78); clipsToBounds = YES; autoresize = W+H; layer = <CALayer: 0x6000017756a0>>","<_UIWindowTransformLayer: 0x60000177a1c0>","setNeedsDisplay: 0x7f8052366770 (HACK)","<UIWindow: 0x7f8052324440; frame = (0 0; 414 78); gestureRecognizers = <NSArray: 0x600001f63510>; layer = <UIWindowLayer: 0x60000177a140>>","setNeedsDisplay: 0x7f805236ae50 (HACK)","LocalDataTask <D7C3D128-6231-4378-9855-72703FB281F5>.<1>","<UILabel: 0x7f8052366770; frame = (0 48; 414 30); text = 'Loading from localhost:80...'; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x6000032c85f0>>","setNeedsDisplay: 0x7f805152d670 (HACK)","setNeedsDisplay: 0x7f805152edf0 (HACK)","<CALayer: 0x6000017756a0>","<CALayer: 0x60000174e980>","<UIViewController: 0x7f80514196c0>","<CALayer: 0x60000174ea80>","<UIWindowLayer: 0x60000177a1a0>","setNeedsDisplay: 0x7f8052366770 (HACK)","setNeedsDisplay: 0x7f8052366770 (HACK)"]}},{"name":"Dispatch Queue","info":{"queue":"<OS_dispatch_queue_main: com.apple.main-thread[0x10c1c0c80] = { xref = -2147483648, ref = -2147483648, sref = 1, target = com.apple.root.default-qos.overcommit[0x10c1c1100], width = 0x1, state = 0x001ffe9000000300, dirty, in-flight = 0, thread = 0x303 }>","prettyPrint":"com.apple.main-thread"}}],"messageId":7,"state":"busy"},"messageId":7}
 
detox[92948] INFO:  [actions.js] Sync Timed: animateWithDuration:animations:
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(synchronizeToDisk) on APMPersistedConfig
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(synchronize) on APMUserDefaults
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication
detox[92948] INFO:  [actions.js] Sync ReactNative JS Loading: React Native is loading Javascript.
detox[92948] INFO:  [actions.js] Sync App State: Waiting for view controller's view to appear
Waiting for network requests to finish
Waiting for window's root view controller's view to appear
Waiting for view's draw or layout pass to complete: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)
detox[92948] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_SEND] {"type":"currentStatus","params":{},"messageId":8}
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=tester action=currentStatus (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [DetoxServer.js/MESSAGE] role=testee action=currentStatusResult (sessionId=097cb438-bccf-1dde-b297-09a210612fc5)
detox[92948] TRACE: [AsyncWebSocket.js/WEBSOCKET_MESSAGE] {"type":"currentStatusResult","params":{"resources":[{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(synchronizeToDisk) on APMPersistedConfig","prettyPrint":"performSelector @selector(synchronizeToDisk) on APMPersistedConfig","duration":2}},{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(synchronize) on APMUserDefaults","prettyPrint":"performSelector @selector(synchronize) on APMUserDefaults","duration":2}},{"name":"WXRunLoopIdlingResource","info":{"runLoop":"<CFRunLoop 0x600002d91a00 [0x108882b80]>{wakeup port = 0x6503, stopped = false, ignoreWakeUps = true, \ncurrent mode = kCFRunLoopDefaultMode,\ncommon modes = <CFBasicHash 0x600001f94f00 [0x108882b80]>{type = mutable set, count = 1,\nentries =>\n\t2 : <CFString 0x1089ff9e8 [0x108882b80]>{contents = \"kCFRunLoopDefaultMode\"}\n}\n,\ncommon mode items = <CFBasicHash 0x600001f8ba80 [0x108882b80]>{type = mutable set, count = 3,\nentries =>\n\t0 : <CFRunLoopTimer 0x6000024c1980 [0x108882b80]>{valid = Yes, firing = No, interval = 0, tolerance = 0, next fire date = 624281537 (488.640915 @ 446625662993194), callout = _ZZN3WTF7RunLoop9TimerBase5startENS_7SecondsEbEN3$_18__invokeEP16__CFRunLoopTimerPv (0x1072a4ae0 / 0x1072a4ae0) (/Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/System/Library/Frameworks/JavaScriptCore.framework/JavaScriptCore), context = <CFRunLoopTimer context 0x1382f64b0>}\n\t1 : <CFRunLoopSource 0x6000024c5a40 [0x108882b80]>{signalled = Yes, valid = Yes, order = 0, context = <CFRunLoopSource context>{version = 0, info = 0x6000013c9930, callout = __NSThreadPerformPerform (0x10593e8a7)}}\n\t2 : <CFRunLoopSource 0x6000024cd680 [0x108882b80]>{signalled = No, valid = Yes, order = 0, context = <CFRunLoopSource context>{version = 0, info = 0x1382f5000, callout = _ZN3WTF7RunLoop11performWorkEPv (0x1072a41a0)}}\n}\n,\nmodes = <CFBasicHash 0x600001f94cf0 [0x108882b80]>{type = mutable set, count = 2,\nentries =>\n\t0 : <CFRunLoopMode 0x600002aca2f0 [0x108882b80]>{name = kCFRunLoopCommonModes, port set = 0x8e03, queue = 0x600003f91880, source = 0x600003f91980 (not fired), timer port = 0x8d03, \n\tsources0 = (null),\n\tsources1 = (null),\n\tobservers = (null),\n\ttimers = (null),\n\tcurrently 624281048 (446137022323770) / soft deadline in: 1.84462979e+10 sec (@ -1) / hard deadline in: 1.84462979e+10 sec (@ -1)\n},\n\n\t2 : <CFRunLoopMode 0x600002ad2d80 [0x108882b80]>{name = kCFRunLoopDefaultMode, port set = 0x6603, queue = 0x600003f8cc00, source = 0x600003f8cd00 (not fired), timer port = 0x9103, \n\tsources0 = <CFBasicHash 0x600001f94ab0 [0x108882b80]>{type = mutable set, count = 3,\nentries =>\n\t0 : <CFRunLoopSource 0x6000024d2280 [0x108882b80]>{signalled = No, valid = Yes, order = 0, context = <CFRunLoopSource context>{version = 0, info = 0x0, callout = ??? (0x0)}}\n\t1 : <CFRunLoopSource 0x6000024c5a40 [0x108882b80]>{signalled = Yes, valid = Yes, order = 0, context = <CFRunLoopSource context>{version = 0, info = 0x6000013c9930, callout = __NSThreadPerformPerform (0x10593e8a7)}}\n\t2 : <CFRunLoopSource 0x6000024cd680 [0x108882b80]>{signalled = No, valid = Yes, order = 0, context = <CFRunLoopSource context>{version = 0, info = 0x1382f5000, callout = _ZN3WTF7RunLoop11performWorkEPv (0x1072a41a0)}}\n}\n,\n\tsources1 = <CFBasicHash 0x600001f94810 [0x108882b80]>{type = mutable set, count = 0,\nentries =>\n}\n,\n\tobservers = (\n    \"<CFRunLoopObserver 0x6000020d59a0 [0x108882b80]>{valid = Yes, activities = 0xe7, repeats = Yes, order = 0, callout = _runLoopObserverWithBlockContext (0x1085009cc), context = <CFRunLoopObserver context 0x600001f95230>}\"\n),\n\ttimers = <CFArray 0x6000035f8420 [0x108882b80]>{type = mutable-small, count = 1, values = (\n\t0 : <CFRunLoopTimer 0x6000024c1980 [0x108882b80]>{valid = Yes, firing = No, interval = 0, tolerance = 0, next fire date = 624281537 (488.640344 @ 446625662993194), callout = _ZZN3WTF7RunLoop9TimerBase5startENS_7SecondsEbEN3$_18__invokeEP16__CFRunLoopTimerPv (0x1072a4ae0 / 0x1072a4ae0) (/Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Library/Developer/CoreSimulator/Profiles/Runtimes/iOS.simruntime/Contents/Resources/RuntimeRoot/System/Library/Frameworks/JavaScriptCore.framework/JavaScriptCore), context = <CFRunLoopTimer context 0x1382f64b0>}\n)},\n\tcurrently 624281048 (446137022335322) / soft deadline in: 488.640658 sec (@ 446625662993194) / hard deadline in: 488.640658 sec (@ 446625662993194)\n},\n\n}\n}\n","prettyPrint":"React Native thread is busy."}},{"name":"Timed","info":{"endTrackingDate":"Tuesday, January 6, 1970 at 4:55:38 AM GMT+01:00","object":"Delayed performSelector","name":"performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication","prettyPrint":"performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication","duration":3}},{"name":"ReactNative JS Loading","info":{"prettyPrint":"React Native is loading Javascript."}},{"name":"App State","info":{"appState":"Waiting for network requests to finish","urls":["http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"],"prettyPrint":"Waiting for network requests to finish: (\n    \"http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false\"\n)","elements":["LocalDataTask <D7C3D128-6231-4378-9855-72703FB281F5>.<1>"]}},{"name":"Dispatch Queue","info":{"queue":"<OS_dispatch_queue_main: com.apple.main-thread[0x10c1c0c80] = { xref = -2147483648, ref = -2147483648, sref = 1, target = com.apple.root.default-qos.overcommit[0x10c1c1100], width = 0x1, state = 0x001ffe9000000300, dirty, in-flight = 0, thread = 0x303 }>","prettyPrint":"com.apple.main-thread"}}],"state":"busy","messageId":8},"messageId":8}
 
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(synchronizeToDisk) on APMPersistedConfig
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(synchronize) on APMUserDefaults
detox[92948] INFO:  [actions.js] Sync WXRunLoopIdlingResource: React Native thread is busy.
detox[92948] INFO:  [actions.js] Sync Timed: performSelector @selector(_accessibilitySetUpQuickSpeak) on UIApplication
detox[92948] INFO:  [actions.js] Sync ReactNative JS Loading: React Native is loading Javascript.
detox[92948] INFO:  [actions.js] Sync App State: Waiting for network requests to finish: (
    "http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false"
)
detox[92948] INFO:  [actions.js] Sync Dispatch Queue: com.apple.main-thread

and then the last few lines repeated over and over

Similar issue: #2305
and seems to be similar issue here: https://stackoverflow.com/questions/63289061/detox-app-stuck-in-launch-screen-on-ios/64030402#64030402

2 thoughts on “detox doesn’t complete ‘launchApp’ when using a debug build

  1. I’m also having the same issue and my environment is the same as the author of this issue. I’m going to remove the splash screen and see if that helps.

    It turns out that it was the splash screen. I disabled it and now the tests are running.

  2. Yeah turns out thats literally it, removed the line that shows the splash screen and tests work completely fine on a dev build. Thanks for all the help, gives us something to go from when working on the tests!

    Might be worth adding something into the docs, I’ll have a read and see where it might fit and put a PR in