search

wix / Detox

Gray box end-to-end testing and automation framework for mobile apps
https://wix.github.io/Detox/
MIT License
11.12k stars 1.91k forks source link

Detox Hangs on launchApp Command #1525

Closed AlexK777 closed 5 years ago

AlexK777 commented 5 years ago

Describe the bug I call detox.init() without launching the app: await detox.init(detoxConfig, {launchApp: false}); and then launch the app afterwards using await device.launchApp({permissions: {location: 'always'}});. The tests are now hanging between the init and launchApp functions, and no tests are ever executed. I am seeing this locally and in all of my CI builds on Bitrise after updating Detox to version 13.1.0. I tested this on the latest version and I see the same thing. If I revert my detox version to 13.0.1, the tests run as expected.

To Reproduce

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.

With Detox 13.1.1

  1. Run the following code at the start of a test run: 
    console.log('Before Init');
await detox.init(detoxConfig, {launchApp: false});
console.log('After Init');
await device.launchApp({permissions: {location: 'always'}});
console.log('After launch');
  2. View output: 
    Before Init
After Init
detox[59313] INFO:  [AppleSimUtils.js] <appName>.debug launched. To watch simulator logs, run:
    /usr/bin/xcrun simctl spawn D22384F5-F2F5-4916-8E21-DADBFD78D646 log stream --level debug --style compact --predicate 'processImagePath beginsWith "/Users/user/Library/Developer/CoreSimulator/Devices/D22384F5-F2F5-4916-8E21-DADBFD78D646/data/Containers/Bundle/Application/0156DD65-D7A1-4F32-858B-2BCFB365D75D/<appName>"'
VError: a BeforeAll hook errored, process exiting: e2e/features/support/hooks.js:31: function timed out, ensure the promise resolves within 90000 milliseconds

With Detox 13.0.1

  1. Run the following code at the start of a test run: 
    console.log('Before Init');
await detox.init(detoxConfig, {launchApp: false});
console.log('After Init');
await device.launchApp({permissions: {location: 'always'}});
console.log('After launch');
  2. View output: 
    
Before Init
After Init
detox[60103] INFO:  [AppleSimUtils.js] <appName> launched. To watch simulator logs, run:
    /usr/bin/xcrun simctl spawn 4ACAE51B-FD28-404C-BA18-767B5919879E log stream --level debug --style compact --predicate 'processImagePath beginsWith "/Users/user/Library/Developer/CoreSimulator/Devices/4ACAE51B-FD28-404C-BA18-767B5919879E/data/Containers/Bundle/Application/7EA51E4E-4AD7-4DD3-A384-4E84B0281FF9/<appName>"'
After launch
..............

1 scenario (1 passed) 4 steps (4 passed) 0m27.588s

**Expected behavior**
App should launch and test execution should begin.

**Screenshots**
The app goes to the background and is never launched. Screenshot would be the home screen of an iOS Simulator. 

**Environment (please complete the following information):**
 - Detox: 13.1.1
 - React Native: 0.59.10
 - Node: 8.11.1
 - Device: iOS Simulator (iPhone X)
 - Xcode: 10.1
 - iOS: 12.1
 - macOS: 10.13.6

**Device and Verbose Detox Logs - 13.1.1**

detox-server info 13:38:36: server listening on localhost:8099... detox-server wss 13:40:12: role=tester login (sessionId=testing) detox-server wss 13:40:12: role=tester action=loginSuccess (sessionId=testing) detox-server wss 13:41:06: role=tester action=isReady (sessionId=testing) detox-server wss 13:41:06: role=testee not connected, cannot fw action (sessionId=testing) detox-server wss 13:41:07: role=testee login (sessionId=testing) detox-server wss 13:41:07: role=testee action=loginSuccess (sessionId=testing) detox-server wss 13:41:08: role=testee disconnect (sessionId=testing) detox-server wss 13:41:42: role=tester disconnect (sessionId=testing)

**Device and Verbose Detox Logs - 13.0.1**

detox-server info 13:47:08: server listening on localhost:8099... detox-server wss 13:47:08: role=testee login (sessionId=testing) detox-server wss 13:47:08: role=testee action=loginSuccess (sessionId=testing) detox-server wss 13:47:12: role=tester login (sessionId=testing) detox-server wss 13:47:12: role=tester action=loginSuccess (sessionId=testing) detox-server wss 13:47:13: role=testee disconnect (sessionId=testing) detox-server wss 13:47:32: role=tester action=isReady (sessionId=testing) detox-server wss 13:47:32: role=testee not connected, cannot fw action (sessionId=testing) detox-server wss 13:47:32: role=testee login (sessionId=testing) detox-server wss 13:47:32: role=testee action=loginSuccess (sessionId=testing) detox-server wss 13:47:35: role=testee action=ready (sessionId=testing) detox-server wss 13:47:35: role=tester action=waitForActive (sessionId=testing) detox-server wss 13:47:35: role=testee action=waitForActiveDone (sessionId=testing) detox-server wss 13:47:36: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:37: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:37: role=tester action=reactNativeReload (sessionId=testing) detox-server wss 13:47:43: role=testee action=ready (sessionId=testing) detox-server wss 13:47:45: role=tester action=reactNativeReload (sessionId=testing) detox-server wss 13:47:50: role=testee action=ready (sessionId=testing) detox-server wss 13:47:50: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:50: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:50: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:50: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:50: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:52: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:52: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:54: role=tester action=invoke (sessionId=testing) detox-server wss 13:47:54: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:47:55: role=tester action=reactNativeReload (sessionId=testing) detox-server wss 13:48:00: role=testee action=ready (sessionId=testing) detox-server wss 13:48:00: role=tester action=invoke (sessionId=testing) detox-server wss 13:48:01: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:48:01: role=tester action=invoke (sessionId=testing) detox-server wss 13:48:02: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:48:02: role=tester action=invoke (sessionId=testing) detox-server wss 13:48:02: role=testee action=invokeResult (sessionId=testing) detox-server wss 13:48:02: role=tester action=cleanup (sessionId=testing) detox-server wss 13:48:02: role=testee action=cleanupDone (sessionId=testing) detox-server wss 13:48:02: role=tester disconnect (sessionId=testing)

LeoNatan commented 5 years ago

I don't see anything in the commits that would suddenly break Detox in 13.1.0 or 13.1.1. Please provide verbose logs as instructed by the issue template.

AlexK777 commented 5 years ago

I'm not sure what is causing the different behavior between versions, but after reverting to 13.0.1 all of our iOS CI builds are green again. I will also add this is only affecting the iOS builds, Android tests run without issue on version 13.1.1.

I implement Detox with cucumber and do not run tests using the detox-cli. I started the detox-server in verbose mode and it provided an additional line at the end.

detox run-server --loglevel verbose
detox[83595] INFO:  [DetoxServer.js] server listening on localhost:8099...
detox[83595] DEBUG: [DetoxServer.js/LOGIN] role=tester, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=tester, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=testing)
detox[83595] DEBUG: [DetoxServer.js/LOGIN] role=testee, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/LOGIN_SUCCESS] role=testee, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/DISCONNECT] role=testee, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/DISCONNECT] role=tester, sessionId=testing
detox[83595] DEBUG: [DetoxServer.js/CANNOT_FORWARD] role=testee not connected, cannot fw action (sessionId=testing)

Device logs when I follow the terminal instructions to tail them:

/usr/bin/xcrun simctl spawn DC703CBB-4B6E-473C-9D56-251CB5C0F95C log stream --level debug --style compact --predicate 'processImagePath beginsWith "/Users/user/Library/Developer/CoreSimulator/Devices/DC703CBB-4B6E-473C-9D56-251CB5C0F95C/data/Containers/Bundle/Application/1CC87F90-474C-4153-B12D-8ABB0AE31758/<appName>"'
Error from getpwuid_r: 0 (Undefined error: 0)
Filtering the log data using "processImagePath BEGINSWITH "/Users/user/Library/Developer/CoreSimulator/Devices/DC703CBB-4B6E-473C-9D56-251CB5C0F95C/data/Containers/Bundle/Application/1CC87F90-474C-4153-B12D-8ABB0AE31758/<appName>""
LeoNatan commented 5 years ago

Does it break builds locally as well?

AlexK777 commented 5 years ago

It does. I can reproduce it each time. I spent some time this morning testing the versions between 13.0.1 and 13.1.0. The breaking change appears between versions 13.0.2 (working) and 13.0.3 (does not work, fails to launch app).

LeoNatan commented 5 years ago

Are you seeing a crash? What do you see in your simulator when the app launches?

LeoNatan commented 5 years ago

If we suspect a crash, please follow the instructions here to catch this crash in Xcode and post your finding: https://github.com/wix/Detox/blob/master/docs/Guide.DebuggingInXcode.md

LeoNatan commented 5 years ago

Ping

AlexK777 commented 5 years ago

I'm alive. I just haven't had a chance to follow the instructions in an attempt to get more details about a possible crash yet. I do believe that is what may be happening. What I see when I try to execute launchApp() is Splash Screen -> Sudden Black Screen -> Simulator stops on iOS home screen and then the tests time out. I should have time to get more info out here in the next day or two.

LeoNatan commented 5 years ago

Yes, that means it's a crash. Please follow the guide I posted. Thanks

AlexK777 commented 5 years ago

@LeoNatan I have implemented the steps to catch the crash. The app just hung on the splash screen when running from Xcode. I am assuming that is due to the crash right after launchApp(), but if that assumption is incorrect we can dig back in. Here is the debug output from Xcode: 

2019-07-15 15:33:50.525410-0500 hyvee.grocery[71658:3822469] Crash handler setup started.
2019-07-15 15:33:50.525801-0500 hyvee.grocery[71658:3822469] Crash handler setup completed.
2019-07-15 15:33:50.526291-0500 hyvee.grocery[71658:3822469] Enabling accessibility for automation on Simulator.
2019-07-15 15:33:50.815132-0500 hyvee.grocery[71658:3822469] [DetoxInstrumentsManager] DTXProfiler class was not found, loading Profiler framework manually
2019-07-15 15:33:50.833770-0500 hyvee.grocery[71658:3822469] [DetoxInstrumentsManager] Error loading Profiler framework bundle. Bundle not found at /Applications/Detox Instruments.app/Contents/SharedSupport/ProfilerFramework/DTXProfiler.framework
2019-07-15 15:33:50.861377-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for RCTUIManagerQueue
2019-07-15 15:33:50.861780-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for JS timers
2019-07-15 15:33:50.861965-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for RN load
2019-07-15 15:33:50.863673-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for Animated display link
2019-07-15 15:33:50.864944-0500 hyvee.grocery[71658:3822469] [DetoxManager] Using default 'detoxServer': ws://localhost:8099
2019-07-15 15:33:50.865042-0500 hyvee.grocery[71658:3822469] [DetoxManager] Using default 'detoxSessionId': com.hyvee.grocery.debug
2019-07-15 15:33:50.955328-0500 hyvee.grocery[71658:3822571]  - <AppMeasurement>[I-ACS036002] Analytics screen reporting is enabled. Call +[FIRAnalytics setScreenName:setScreenClass:] to set the screen name or override the default screen class name. To disable screen reporting, set the flag FirebaseScreenReportingEnabled to NO (boolean) in the Info.plist
2019-07-15 15:33:50.988031-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Found modern class RCTCxxBridge, method runRunLoop
2019-07-15 15:33:51.264988-0500 hyvee.grocery[71658:3822469] [AXMediaCommon] Unable to look up screen scale
2019-07-15 15:33:51.265072-0500 hyvee.grocery[71658:3822469] [AXMediaCommon] Unexpected physical screen orientation
2019-07-15 15:33:51.282094-0500 hyvee.grocery[71658:3822469] [WebSocket] Action Sent: login
2019-07-15 15:33:51.288176-0500 hyvee.grocery[71658:3822469] [AXMediaCommon] Unable to look up screen scale
2019-07-15 15:33:51.290816-0500 hyvee.grocery[71658:3822469] [AXMediaCommon] Unable to look up screen scale
2019-07-15 15:33:51.290893-0500 hyvee.grocery[71658:3822469] [AXMediaCommon] Unexpected physical screen orientation
2019-07-15 15:33:51.291725-0500 hyvee.grocery[71658:3822469] [WebSocket] Action Received: loginSuccess
2019-07-15 15:33:51.368739-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
[FIREBASE] Debug mode
2019-07-15 15:33:51.381544-0500 hyvee.grocery[71658:3822548] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
2019-07-15 15:33:51.384363-0500 hyvee.grocery[71658:3822548] 5.20.0 - [Firebase/Analytics][I-ACS025020] Analytics requires Google App ID from GoogleService-Info.plist. Your data may be lost. Google App ID has been changed. Original, new ID: 1:666606465265:ios:9945b086acb95e71, 1:666606465265:ios:96065da880c59e11
2019-07-15 15:33:51.389435-0500 hyvee.grocery[71658:3822469] [MC] System group container for systemgroup.com.apple.configurationprofiles path is /Users/akoon/Library/Developer/CoreSimulator/Devices/92B9FD3F-B0AD-497C-AA6D-DA77BD051E3D/data/Containers/Shared/SystemGroup/systemgroup.com.apple.configurationprofiles
2019-07-15 15:33:51.390924-0500 hyvee.grocery[71658:3822469] [MC] Reading from private effective user settings.
2019-07-15 15:33:51.397090-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
2019-07-15 15:33:51.406615-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
2019-07-15 15:33:51.409459-0500 hyvee.grocery[71658:3822548] 5.20.0 - [Firebase/Analytics][I-ACS023007] Analytics v.50801000 started
2019-07-15 15:33:51.409726-0500 hyvee.grocery[71658:3822548] 5.20.0 - [Firebase/Analytics][I-ACS023008] To enable debug logging set the following application argument: -FIRAnalyticsDebugEnabled (see http://goo.gl/RfcP7r)
2019-07-15 15:33:51.412341-0500 hyvee.grocery[71658:3822722] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.412418-0500 hyvee.grocery[71658:3822548] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.412487-0500 hyvee.grocery[71658:3822722] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.412589-0500 hyvee.grocery[71658:3822723] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commc2019-07-15 15:33:51.412603-0500 hyvee.grocery[71658:3822548] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
enter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.412869-0500 hyvee.grocery[71658:3822723] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.413278-0500 hyvee.grocery[71658:3822722] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.413315-0500 hyvee.grocery[71658:3822723] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.413416-0500 hyvee.grocery[71658:3822722] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.413488-0500 hyvee.grocery[71658:3822548] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.413994-0500 hyvee.grocery[71658:3822722] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.414111-0500 hyvee.grocery[71658:3822548] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.414215-0500 hyvee.grocery[71658:3822722] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.414437-0500 hyvee.grocery[71658:3822723] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.424935-0500 hyvee.grocery[71658:3822548] 5.20.0 - [Firebase/Messaging][I-FCM001000] FIRMessaging Remote Notifications proxy enabled, will swizzle remote notification receiver handlers. If you'd prefer to manually integrate Firebase Messaging, add "FirebaseAppDelegateProxyEnabled" to your Info.plist, and set it to NO. Follow the instructions at:
https://firebase.google.com/docs/cloud-messaging/ios/client#method_swizzling_in_firebase_messaging
to ensure proper integration.
2019-07-15 15:33:51.427725-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
2019-07-15 15:33:51.448 [info][tid:main][RCTCxxBridge.mm:213] Initializing <RCTCxxBridge: 0x7ff24970a230> (parent: <RCTBridge: 0x60000127a920>, executor: (null))
2019-07-15 15:33:51.448445-0500 hyvee.grocery[71658:3822469] Initializing <RCTCxxBridge: 0x7ff24970a230> (parent: <RCTBridge: 0x60000127a920>, executor: (null))
2019-07-15 15:33:51.449178-0500 hyvee.grocery[71658:3822736] [ReactNativeSupport] Adding idling resource for JS runloop
2019-07-15 15:33:51.562 [info][tid:main][RCTBridge.m:134] Class RNFaceDetectorModuleMLKit was not exported. Did you forget to use RCT_EXPORT_MODULE()?
2019-07-15 15:33:51.562455-0500 hyvee.grocery[71658:3822469] Class RNFaceDetectorModuleMLKit was not exported. Did you forget to use RCT_EXPORT_MODULE()?
2019-07-15 15:33:51.597 [warn][tid:main][RCTModuleData.mm:67] Module LogModule requires main queue setup since it overrides `init` but doesn't implement `requiresMainQueueSetup`. In a future release React Native will default to initializing all native modules on a background thread unless explicitly opted-out of.
2019-07-15 15:33:51.597031-0500 hyvee.grocery[71658:3822469] Module LogModule requires main queue setup since it overrides `init` but doesn't implement `requiresMainQueueSetup`. In a future release React Native will default to initializing all native modules on a background thread unless explicitly opted-out of.
2019-07-15 15:33:51.597 [warn][tid:main][RCTModuleData.mm:67] Module VoiceModule requires main queue setup since it overrides `init` but doesn't implement `requiresMainQueueSetup`. In a future release React Native will default to initializing all native modules on a background thread unless explicitly opted-out of.
2019-07-15 15:33:51.597378-0500 hyvee.grocery[71658:3822469] Module VoiceModule requires main queue setup since it overrides `init` but doesn't implement `requiresMainQueueSetup`. In a future release React Native will default to initializing all native modules on a background thread unless explicitly opted-out of.
2019-07-15 15:33:51.597900-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNNEventEmitterQueue>
2019-07-15 15:33:51.599196-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for network queue: <OS_dispatch_queue_serial: com.apple.NSURLSession-work>
2019-07-15 15:33:51.683569-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNDeviceInfoQueue>
2019-07-15 15:33:51.690380-0500 hyvee.grocery[71658:3822469] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.690412-0500 hyvee.grocery[71658:3822730] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.690531-0500 hyvee.grocery[71658:3822469] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.690627-0500 hyvee.grocery[71658:3822730] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.690627-0500 hyvee.grocery[71658:3822722] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.690976-0500 hyvee.grocery[71658:3822722] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.691204-0500 hyvee.grocery[71658:3822469] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.691269-0500 hyvee.grocery[71658:3822722] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.691322-0500 hyvee.grocery[71658:3822469] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.691473-0500 hyvee.grocery[71658:3822730] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.692141-0500 hyvee.grocery[71658:3822469] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.692241-0500 hyvee.grocery[71658:3822722] [Client] Remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.692375-0500 hyvee.grocery[71658:3822469] [NetworkInfo] Descriptors query returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.692728-0500 hyvee.grocery[71658:3822732] [Client] Sending selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service named com.apple.commcenter.coretelephony.xpc was invalidated.}
2019-07-15 15:33:51.863 [warn][tid:NSOperationQueue 0x600003905860 (QOS: UNSPECIFIED)][RCTModuleData.mm:248] RCTBridge required dispatch_sync to load RCTDevLoadingView. This may lead to deadlocks
2019-07-15 15:33:51.863637-0500 hyvee.grocery[71658:3822548] RCTBridge required dispatch_sync to load RCTDevLoadingView. This may lead to deadlocks
2019-07-15 15:33:51.906273-0500 hyvee.grocery[71658:3822469] -[RNFirebaseMessaging init] [Line 33] Setting up RNFirebaseMessaging instance
2019-07-15 15:33:51.906603-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNFirebaseMessagingQueue>
2019-07-15 15:33:51.906823-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: io.invertase.react-native-firebase.firestore>
2019-07-15 15:33:51.906964-0500 hyvee.grocery[71658:3822469] -[RNFirebase init] [Line 18] Setting up RNFirebase instance
2019-07-15 15:33:51.907102-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNFirebaseQueue>
2019-07-15 15:33:51.907321-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: io.invertase.react-native-firebase.database>
2019-07-15 15:33:51.907470-0500 hyvee.grocery[71658:3822469] -[RNFirebaseNotifications init] [Line 46] Setting up RNFirebaseNotifications instance
2019-07-15 15:33:51.915356-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNFirebaseNotificationsQueue>
2019-07-15 15:33:51.915701-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.RNFirebasePerformanceQueue>
2019-07-15 15:33:51.918552-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.AccessibilityManagerQueue>
2019-07-15 15:33:51.918942-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.DevLoadingViewQueue>
2019-07-15 15:33:51.919476-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.PlatformConstantsQueue>
2019-07-15 15:33:51.920058-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.ReactNativeConfigQueue>
2019-07-15 15:33:51.920452-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.LogModuleQueue>
2019-07-15 15:33:51.920709-0500 hyvee.grocery[71658:3822469] [ReactNativeSupport] Adding idling resource for queue: <OS_dispatch_queue_serial: com.facebook.react.VoiceModuleQueue>
2019-07-15 15:33:51.951905-0500 hyvee.grocery[71658:3822733] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C2.1:2][0x7ff24e801040] get output frames failed, state 8196
2019-07-15 15:33:51.952073-0500 hyvee.grocery[71658:3822733] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C2.1:2][0x7ff24e801040] get output frames failed, state 8196
2019-07-15 15:33:51.952634-0500 hyvee.grocery[71658:3822733] TIC Read Status [2:0x0]: 1:57
2019-07-15 15:33:51.952753-0500 hyvee.grocery[71658:3822733] TIC Read Status [2:0x0]: 1:57
2019-07-15 15:33:51.954869-0500 hyvee.grocery[71658:3822733] [] nw_socket_handle_socket_event [C7.1:1] Socket SO_ERROR [61: Connection refused]

I hope something in here turns out to be useful.

LeoNatan commented 5 years ago

I don't see a crash here. If the app hung, please run again in Xcode, let it hang, hit the pause button, and type the following in the debug prompt (bottom section, right pane): bt Post the output here. Thanks

AlexK777 commented 5 years ago

Here is what I see after doing that. 


bt
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=2, address=0x7ffee9fe9ff8)
    frame #0: 0x000000010a43984d libobjc.A.dylib`objc::DenseMapBase<objc::DenseMap<DisguisedPtr<objc_object>, unsigned long, true, objc::DenseMapInfo<DisguisedPtr<objc_object> > >, DisguisedPtr<objc_object>, unsigned long, objc::DenseMapInfo<DisguisedPtr<objc_object> >, true>::FindAndConstruct(DisguisedPtr<objc_object> const&) + 23
    frame #1: 0x000000010a437b18 libobjc.A.dylib`objc_object::sidetable_retain() + 86
    frame #2: 0x000000010a436fe9 libobjc.A.dylib`objc_storeStrong + 32
  * frame #3: 0x00000001095f043a Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x0000000000000000) at DetoxAppDelegateProxy.m:317
    frame #4: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #5: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #6: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #7: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #8: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #9: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #10: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #11: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #12: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #13: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #14: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #15: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80,
    frame #34869: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34870: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34871: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34872: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34873: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34874: 0x00000001095f04af Detox`-[DetoxAppDelegateProxy applicationDidBecomeActive:](self=0x0000600003423e80, _cmd="applicationDidBecomeActive:", application=0x00007ff570e02d40) at DetoxAppDelegateProxy.m:323
    frame #34875: 0x000000011a4b0a71 UIKitCore`-[UIApplication _stopDeactivatingForReason:] + 1192
    frame #34876: 0x0000000119cdab95 UIKitCore`__125-[_UICanvasLifecycleSettingsDiffAction performActionsForCanvas:withUpdatedScene:settingsDiff:fromSettings:transitionContext:]_block_invoke + 845
    frame #34877: 0x0000000119cdb80e UIKitCore`_performActionsWithDelayForTransitionContext + 100
    frame #34878: 0x0000000119cda7ef UIKitCore`-[_UICanvasLifecycleSettingsDiffAction performActionsForCanvas:withUpdatedScene:settingsDiff:fromSettings:transitionContext:] + 221
    frame #34879: 0x0000000119cdf93a UIKitCore`-[_UICanvas scene:didUpdateWithDiff:transitionContext:completion:] + 392
    frame #34880: 0x000000011a05c1f5 UIKitCore`-[UIApplicationSceneClientAgent scene:handleEvent:withCompletion:] + 502
    frame #34881: 0x0000000119163fdb FrontBoardServices`__80-[FBSSceneImpl updater:didUpdateSettings:withDiff:transitionContext:completion:]_block_invoke.359 + 213
    frame #34882: 0x000000010eee7602 libdispatch.dylib`_dispatch_client_callout + 8
    frame #34883: 0x000000010eeeab78 libdispatch.dylib`_dispatch_block_invoke_direct + 301
    frame #34884: 0x00000001191a2ba8 FrontBoardServices`__FBSSERIALQUEUE_IS_CALLING_OUT_TO_A_BLOCK__ + 30
    frame #34885: 0x00000001191a2860 FrontBoardServices`-[FBSSerialQueue _performNext] + 457
    frame #34886: 0x00000001191a2e40 FrontBoardServices`-[FBSSerialQueue _performNextFromRunLoopSource] + 45
    frame #34887: 0x000000010b9c1721 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
    frame #34888: 0x000000010b9c0f93 CoreFoundation`__CFRunLoopDoSources0 + 243
    frame #34889: 0x000000010b9bb63f CoreFoundation`__CFRunLoopRun + 1263
    frame #34890: 0x000000010b9bae11 CoreFoundation`CFRunLoopRunSpecific + 625
    frame #34891: 0x0000000128235b53 EarlGrey`-[GREYRunLoopSpinner grey_drainRunLoopInActiveModeAndCheckCondition:forTime:](self=0x0000600003b1f8d0, _cmd="grey_drainRunLoopInActiveModeAndCheckCondition:forTime:", stopConditionBlock=0x00000001282869f0, time=1.7976931348623157E+308) at GREYRunLoopSpinner.m:175
    frame #34892: 0x00000001282354be EarlGrey`-[GREYRunLoopSpinner spinWithStopConditionBlock:](self=0x0000600003b1f8d0, _cmd="spinWithStopConditionBlock:", stopConditionBlock=0x00000001282869f0) at GREYRunLoopSpinner.m:58
    frame #34893: 0x00000001282860e4 EarlGrey`-[GREYUIThreadExecutor executeSyncWithTimeout:block:error:](self=0x0000600003415160, _cmd="executeSyncWithTimeout:block:error:", seconds=1.7976931348623157E+308, execBlock=0x00000001095e56a0, error=0x0000000000000000) at GREYUIThreadExecutor.m:227
    frame #34894: 0x0000000128285b13 EarlGrey`-[GREYUIThreadExecutor executeSync:error:](self=0x0000600003415160, _cmd="executeSync:error:", execBlock=0x00000001095e56a0, error=0x0000000000000000) at GREYUIThreadExecutor.m:198
    frame #34895: 0x00000001095e566e Detox`__45-[EarlGreyImpl(.block_descriptor=0x0000600003b145a0) detox_safeExecuteSync:]_block_invoke at EarlGrey+Detox.m:17
    frame #34896: 0x000000010b9c162c CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__ + 12
    frame #34897: 0x000000010b9c0de0 CoreFoundation`__CFRunLoopDoBlocks + 336
    frame #34898: 0x000000010b9bb654 CoreFoundation`__CFRunLoopRun + 1284
    frame #34899: 0x000000010b9bae11 CoreFoundation`CFRunLoopRunSpecific + 625
    frame #34900: 0x000000010f82b1dd GraphicsServices`GSEventRunModal + 62
    frame #34901: 0x00000001095eae36 Detox`__detox_UIApplication_run(self=0x00007ff570e02d40, _cmd="_run") at ReactNativeSupport.m:143
    frame #34902: 0x000000011a4ba81d UIKitCore`UIApplicationMain + 140
    frame #34903: 0x000000010541a5c7 hyvee.grocery`main at AppDelegate.swift:7
    frame #34904: 0x000000010ef5d575 libdyld.dylib`start + 1
    frame #34905: 0x000000010ef5d575 libdyld.dylib`start + 1
LeoNatan commented 5 years ago

Oh boy. What analytic frameworks do you use? I see you have Firebase. Anything else? I fear there might be some conflict somewhere which is causing this. (This is a stack overflow due to clash in swizzling)

AlexK777 commented 5 years ago

The only other thing I can think of along those lines would be Sentry for error tracking.

LeoNatan commented 5 years ago

I will take a look again at the code to try and figure something out.

LeoNatan commented 5 years ago

Would you mind testing a debugging branch of Detox? I'd like to pepper some debug messages to understand where things break.

LeoNatan commented 5 years ago

Please recursively clone the AppDelegateSwizzleWoes branch like so:

git clone --single-branch --branch AppDelegateSwizzleWoes --recursive https://github.com/wix/Detox.git

Then follow the above linked guide, only dragging the newly cloned project from detox/ios rather than from node_modules.

Before building and running in Xcode, open a new terminal window and run the following command:

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

Now run in Xcode and let it hang. Copy the output from Terminal and paste here. Thanks!

elyalvarado commented 5 years ago

I just want to point that I'm experiencing the same issue, with Detox 13.1.0 on iOS, it happens enough to interrupt at least one test of a suit of 7 tests every time I run it completely . If I start the app manually the tests continue (which of course I can't do on CI where it times out).

I'm using Branch for Analytics

LeoNatan commented 5 years ago

@elyalvarado This problem specifically, if it happens, it happens every time. Otherwise, it's something else.

LeoNatan commented 5 years ago

Good news, I've implemented a new method that goes away from swizzling the app delegate. @AlexK777 Please test as described above and see if your issue is fixed.

AlexK777 commented 5 years ago

👍I will be able to do so this afternoon.

AlexK777 commented 5 years ago

@LeoNatan it looks like your branch does fix the issue. When I ran the app from Xcode I was actually able to navigate around instead of it hanging on the splash screen. I was even able to run some tests!

................................................

4 scenarios (4 passed)
22 steps (22 passed)
0m40.917s
LeoNatan commented 5 years ago

Great, I’ll merge it and release a new build with the fix. Thanks

LeoNatan commented 5 years ago

13.2.0 is out

AlexK777 commented 5 years ago

Confirming this issue has been fixed in 13.2.0. Thanks @LeoNatan.