ios-webkit-debug-proxy crash on iOS8 while putting the app in background

ijazsarwar commented 9 years ago

Hi,

We are able to run our tests. But as soon as test tries to put the app in background ios-webkit-debug-proxy seams to get crashed and I get followig error:

Invalid message _rpc_applicationUpdated:

WIRApplicationIdentifierKey

<string>PID:3050</string>
<key>WIRIsApplicationProxyKey</key>
<false/>
<key>WIRApplicationNameKey</key>
<string>Netflix</string>
<key>WIRApplicationBundleIdentifierKey</key>
<string>com.netflix.Netflix</string>
<key>WIRIsApplicationActiveKey</key>
<integer>0</integer>

ss.remove_fd(6) Disconnected :27753 from ....

Appium server logs are here:

2015-01-28 00:51:52:386 - info: [debug] [REMOTE] Disconnecting from remote debugger 2015-01-28 00:51:52:388 - info: --> POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/appium/app/background {"seconds":10} 2015-01-28 00:51:52:389 - info: [debug] Pushing command to appium work queue: "au.background(10)" 2015-01-28 00:51:52:390 - info: [debug] Sending command to instruments: au.background(10) 2015-01-28 00:51:52:414 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] ====== IDS Traffic Usage: 2015-01-28 00:51:52:415 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] Service: com.apple.private.alloy.bulletinboard 2015-01-28 00:51:52:417 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] incoming-messages: 43 2015-01-28 00:51:52:420 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] 2015-01-28 00:51:52:423 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] Service: com.apple.private.alloy.phonecontinuity 2015-01-28 00:51:52:427 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] incoming-messages: 17 2015-01-28 00:51:52:433 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] 2015-01-28 00:51:52:434 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad identityservicesd[46] : [Warning] ====== Done

2015-01-28 00:51:52:543 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:53 Ijazs-iPad discoveryd[53] : Basic Sockets SetDelegatePID() failed for PID[2296] errno[3] result[-1] 2015-01-28 00:51:52:580 - info: --> GET /wd/hub/status {} 2015-01-28 00:51:52:581 - info: [debug] Responding to client with success: {"status":0,"value":{"build":{"version":"1.3.4","revision":"c8c79a85fbd6870cd6fc3d66d038a115ebe22efe"},"isShuttingDown":false},"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:52:581 - info: <-- GET /wd/hub/status 200 0.531 ms - 178 {"status":0,"value":{"build":{"version":"1.3.4","revision":"c8c79a85fbd6870cd6fc3d66d038a115ebe22efe"},"isShuttingDown":false},"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:52:591 - info: [debug] [INST] 2015-01-28 00:51:53 +0000 Debug: Got new command 26 from instruments: au.background(10) 2015-01-28 00:51:52:594 - info: [debug] [INST] 2015-01-28 00:51:53 +0000 Debug: evaluating au.background(10) 2015-01-28 00:51:52:596 - info: [debug] [INST] 2015-01-28 00:51:53 +0000 Debug: target.deactivateAppForDuration("10")

2015-01-28 00:51:53:150 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:54 Ijazs-iPad locationd[58] : Gesture EnabledForTopCLient: 0, EnabledInDaemonSettings: 0

2015-01-28 00:51:53:689 - info: [debug] [INST] 2015-01-28 00:51:54 +0000 Debug: evaluation finished

2015-01-28 00:51:53:693 - info: [debug] [INST] 2015-01-28 00:51:54 +0000 Debug: responding with:

2015-01-28 00:51:53:697 - info: [debug] [INST] 2015-01-28 00:51:54 +0000 Debug: Running system command #27: /Users/isarwar/Downloads/Appium.app/Contents/Resources/node/bin/node /Users/isarwar/Downloads/Appium.app/Contents/Resources/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}... 2015-01-28 00:51:53:740 - info: [debug] Socket data received (28 bytes) 2015-01-28 00:51:53:740 - info: [debug] Socket data being routed. 2015-01-28 00:51:53:740 - info: [debug] Got result from instruments: {"status":0,"value":false} 2015-01-28 00:51:53:740 - info: [debug] Responding to client with success: {"status":0,"value":false,"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:53:740 - info: <-- POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/appium/app/background 200 1352.074 ms - 77 {"status":0,"value":false,"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:53:743 - info: --> GET /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/contexts {} 2015-01-28 00:51:53:744 - info: [debug] [REMOTE] Getting WebKitRemoteDebugger pageArray 2015-01-28 00:51:53:745 - info: [debug] Responding to client with success: {"status":0,"value":["NATIVE_APP","WEBVIEW_1"],"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:53:745 - info: <-- GET /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/contexts 200 1.766 ms - 98 {"status":0,"value":["NATIVE_APP","WEBVIEW_1"],"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:53:748 - info: --> POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/context {"name":"WEBVIEW_1"} 2015-01-28 00:51:53:748 - info: [debug] Attempting to set context to 'WEBVIEW_1' 2015-01-28 00:51:53:750 - info: [debug] [REMOTE] Debugger web socket connected to url [ws://localhost:27753/devtools/page/1] 2015-01-28 00:51:53:750 - info: [debug] Responding to client with success: {"status":0,"value":"WEBVIEW_1","sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:53:750 - info: <-- POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/context 200 2.185 ms - 83 {"status":0,"value":"WEBVIEW_1","sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"}

2015-01-28 00:51:53:891 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:55 Ijazs-iPad mediaserverd[1037] : 'FigPlayer - 28' (pid = 28) setting DiscoveryMode = DiscoveryMode_None, currentDiscoveryMode = DiscoveryMode_PresenceScan 2015-01-28 00:51:53:895 - info: [IOS_SYSLOG_ROW ] Jan 27 16:51:55 Ijazs-iPad mediaserverd[1037] : 2015-01-27 04:51:55.247230 PM [AirPlay] BTLE client stopping to browse for AirPlay Solo Target Presence.

2015-01-28 00:51:54:453 - info: --> GET /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/contexts {}

2015-01-28 00:51:54:454 - info: [debug] [REMOTE] Getting WebKitRemoteDebugger pageArray 2015-01-28 00:51:54:455 - info: [debug] Responding to client with success: {"status":0,"value":["NATIVE_APP","WEBVIEW_1"],"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"}

2015-01-28 00:51:54:456 - info: <-- GET /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/contexts 200 2.308 ms - 98 {"status":0,"value":["NATIVE_APP","WEBVIEW_1"],"sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:54:459 - info: --> POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/context {"name":"NATIVE_APP"} 2015-01-28 00:51:54:459 - info: [debug] Attempting to set context to 'NATIVE_APP' 2015-01-28 00:51:54:460 - info: [debug] Responding to client with success: {"status":0,"value":"","sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:54:460 - info: <-- POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/context 200 1.087 ms - 74 {"status":0,"value":"","sessionId":"b63a6939-148d-4f9b-b2fa-9afdae78a5fb"} 2015-01-28 00:51:54:460 - info: [debug] [REMOTE] Disconnecting from remote debugger 2015-01-28 00:51:54:463 - info: --> POST /wd/hub/session/b63a6939-148d-4f9b-b2fa-9afdae78a5fb/element {"using":"id","value":"scrubber"} ....

jlipps commented 9 years ago

Unfortunately, Apple broke backgroundApp in iOS8. It now crashes the application :-(

ijazsarwar commented 9 years ago

@jlipps Thanks for prompt response!

oops - is there any alternate way? Is Apple expected to fix it? probably I should go and create bug in their database.

jlipps commented 9 years ago

yes, Apple does not show what they're working on so we have no way to know whether to expect a fix. Please do drop a bug in Radar! (But please reproduce it using UIAutomation alone, without Appium, otherwise they won't know how to repro for themselves)

ijazsarwar commented 9 years ago

I think we should reopen this ticket because using Apple instruments I am able to put the app in background. With the same Mac and iPad, Appium does not work. So which means probably there might be some issue in Appium. Below script in instrument works fine (I tried with iOS 8.1.2 and iOS 8.1.3 device):

var target = UIATarget.localTarget();

// wait for 5 seconds while app is launching var ms = 5000 + new Date().getTime(); while (new Date() < ms){}

// background the app for 10 seconds (which works fine and after 10 sec the app comes back in foreground) target.deactivateAppForDuration(10);

ijazsarwar commented 9 years ago

@jlipps can you please take a look at this when you get a chance? Background and locking is a very commons customer scenario for any app.

jlipps commented 9 years ago

If it works with UIAutomation, then it should work with Appium.

ijazsarwar commented 9 years ago

Actually after upgrading xcode (6.2), pulling latest code from Appium and with iPad iOS 8.2 - background/lockscreen test cases worked fine and passed.

adrianmatean commented 9 years ago

Hi all, I am struggling with this issue (backgrounding the app) for the past 5 days, on real devices. Appium 1.4.0, Xcode 6.3.1

Here are my findings:

it is clearly an instruments issue, since the command behaves the same if triggered from Appium or Instruments Automation
it happens only on certain devices. For my iPhone 6 Plus with iOS 8.0.2 it works fine, but for iPhone 5C with iOS 8.2 it doesn't.
for a short while, it worked even on the 5C, but I don't know what triggered the success of the command. After one week, it started misbehaving again, without any apparent reason.
I tried to factory reset the iPhone 5C, with the same behavior afterwards.
still have no idea what is the difference between the devices, except iOS version, which I believe is not the cause of the problem. Will come back with any more findings, if the case.

adrianmatean commented 9 years ago

Hi all,

I have found a workaround provided by calabash. It works for me. The original issue can be found at https://github.com/calabash/calabash-ios/commit/6935245605d1fd44c223155972703e89247857ec

Apparently retrying the uia command does the trick.

I replaced the original

driver.runAppInBackground(2);

with

JavascriptExecutor jse = (JavascriptExecutor) driver;
jse.executeScript("var x = target.deactivateAppForDuration(2); var MAX_RETRY=5, retry_count = 0; while (!x && retry_count < MAX_RETRY) { x = target.deactivateAppForDuration(2); retry_count += 1}; x");

jrichardlai commented 8 years ago

deactivateAppForDuration seems to be broken for iOS9.

sankritraj commented 8 years ago

Error org.openqa.selenium.WebDriverException: An error occurred while executing user supplied JavaScript. (WARNING: The server did not provide any stacktrace information) Command duration or timeout: 10.54 seconds

Appears while using any javascript executor for appium even it is set in capabilities.

any solutions for this

lock[bot] commented 5 years ago

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

appium / appium

ios-webkit-debug-proxy crash on iOS8 while putting the app in background #4451