WDA/iProxy don't respond: Connection to WDA timed out / recv failed: Operation not permitted

[felyppers]

The problem

WDA crashes trying to connect to device (iOS 11.2.1) using Appium. I've already opened a ticket in Appium repository, but their conclusion pointed that WDA crashed. Using the same app and capabilities, other devices (ios 9.3 until 10.3.3) are able to connect. All info I could collect is available down below, but please let me know if anything else is necessary.

Environment

• Appium version (or git revision) that exhibits the issue: 1.7.2-beta2
• Desktop OS/version: MacOS Sierra 10.12.16
• Mobile platform/version under test: iPad Mini 2 - iOS 11.2.1 (Xcode 9.2)
• Real device or emulator/simulator: Real device

Details

Starting tests on an iPad Mini 2 (iOS 11.2.1) results in WDA not being able to connect to the device. All other devices in our farm (all between iOS 9.3 and 10.3.3) connect without a problem. Basically the WDA opens, the application is launched, but in the log we can already see the connection issue. If we try to call any WDA method, the app gets closed.

Link to logs

Appium Log: Until row 148 no method was called, I just started the appium driver. The application launched correctly. Beyond this point, I called findElements, resulting in the application being closed.

XCodeBuild Log: Log generated by xcodebuild after the issue.

Device Log: Log indicating that WDA crashed.

[shivakrishnach31]

I am also facing the same issue. This is very serious issue for me as we have multiple picker wheel classes in a screen to support voice over. So whenever I try to perform action on a picker wheel elements app is crashing. @marekcirkos Could you please fix this.

I am using Xcode 9.2, iOS 11.1.2 and 11.2, Appium 1.6.4 and 1.7.1

[Justinidlerz]

I am also facing the same issue too. but different my device is iphone x.
I am using Xcode 9.2, iOS 11.1.2, Appium 1.7.1

[felyppers]

No news on this?

[shivakrishnach31]

@marekcirkos @imurchie @mykola-mokhnach - Could any one of you please look into this issue.

[felyppers]

@mykola-mokhnach already did, however it is not an appium issue =/

[terrium88]

I am also facing the same issue too.
I am using Xcode 9.2, iOS 11.1.2 and 11.2, Appium 1.7.1.

Is any way to solve this issue, it affects the tests!
@mykola-mokhnach @imurchie

Maybe write to the support WebDriverAgent

[marekcirkos]

@felyppers How did you concluded that this is WDA crash? I cannot see anything in that logs except that there is assertion firing in some game app and killing it.

[felyppers]

@marekcirkos thanks for your response. Actually I didn't. I first reported this issue in Appium Github. @mykola-mokhnach noticed that the xcodebuild log provided above indicated that WDA was crashing unexpectedly. The specific log part that @mykola-mokhnach indicated was this one:

2017-12-20 15:55:21.448651-0200 WebDriverAgentRunner-Runner[448:26204] Running tests...
2017-12-20 15:55:22.117620-0200 WebDriverAgentRunner-Runner[448:26204] refreshPreferences: HangTracerEnabled: 0
2017-12-20 15:55:22.117752-0200 WebDriverAgentRunner-Runner[448:26204] refreshPreferences: HangTracerDuration: 500
2017-12-20 15:55:22.117799-0200 WebDriverAgentRunner-Runner[448:26204] refreshPreferences: ActivationLoggingEnabled: 0 ActivationLoggingTaskedOffByDA:0
2017-12-20 15:55:24.158631-0200 WebDriverAgentRunner-Runner[448:26204] [AXValidations] UIAccessibility Error adding -[PHAsset accessibilityLabel]
2017-12-20 15:55:24.158841-0200 WebDriverAgentRunner-Runner[448:26204] [AXValidations] UIAccessibility Error adding -[PHAsset accessibilityValue]
2017-12-20 15:55:24.158933-0200 WebDriverAgentRunner-Runner[448:26204] [AXValidations] UIAccessibility Error adding -[PHAsset accessibilityTraits]
2017-12-20 15:55:24.159021-0200 WebDriverAgentRunner-Runner[448:26204] [AXValidations] UIAccessibility Error adding -[PHAsset _accessibilitySavePhotoLabel:]
2017-12-20 15:55:24.159144-0200 WebDriverAgentRunner-Runner[448:26204] [AXValidations] UIAccessibility Error adding +[PHAsset safeCategoryBaseClass]
2017-12-20 15:55:24.320781-0200 WebDriverAgentRunner-Runner[448:26204] Continuing to run tests in the background with task ID 1
Restarting after unexpected exit or crash in UITestingUITests/testRunner; summary will include totals from previous launches.

Hope this helps.

[guianselmi]

Any solution already? I'm still facing this issue

[skansar]

Creating new XCUITestDriver (v2.30.0) session
[Appium] Capabilities:
[Appium] app: 'Settings'
[Appium] newCommandTimeout: 380
[Appium] platformVersion: '11.2'
[Appium] xcodeOrgId: 'NNNnnnnnnnnn'
[Appium] automationName: 'XCUITest'
[Appium] platformName: 'iOS'
[Appium] udid: '******************25adea5f44'
[Appium] deviceName: 'IOSDevice'
[Appium] xcodeSigningId: 'iPhone Developer'

MobileElement Click() does not work. facing the same issue

[HTTP] <-- GET /wd/hub/session/f7aa89d9-c6c0-4606-8d6f-cc3a7836bc3d/window_handles 501 2 ms - 112
[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted

[skansar]

[HTTP] <-- GET /wd/hub/session/f7aa89d9-c6c0-4606-8d6f-cc3a7836bc3d/window_handles 501 2 ms - 112
[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted

[benz-philip]

After a set of test cases are executed, the execution hangs and log message is as follows,

[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted
[BaseDriver] Shutting down because we waited 60 seconds for a command
[Appium] Closing session, cause was 'New Command Timeout of 60 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability'
[Appium] Removing session 2c4df441-39a2-4854-ab57-79cba9a4107d from our master session list

This is a blocker and not able to run all my test cases. Please suggest a workaround for this.

Thank you!

[s2005lg]

I got the same issue now.
[HTTP] <-- POST /wd/hub/session 200 6518 ms - 603
[HTTP]
[HTTP] --> POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/url
[HTTP] {"url":"https://www.baidu.com/"}
[debug] [W3C] Calling AppiumDriver.setUrl() with args: ["https://www.baidu.com/","faadf600-ae4c-4ffd-8fe0-c2e936282f89"]
[debug] [XCUITest] Executing command 'setUrl'
[debug] [iOS] Attempting to set url 'https://www.baidu.com/'
[debug] [RemoteDebugger] Navigating to new URL: https://www.baidu.com/
[debug] [RemoteDebugger] Sending WebKit data: {"method":"Page.navigate","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true,"url":"https://www.baidu.com/"}}
[debug] [RemoteDebugger] Webkit response timeout: 5000
[debug] [RemoteDebugger] Receiving WebKit data: '{"result":{},"id":1}'
[debug] [RemoteDebugger] Found handler for message '1'
[debug] [RemoteDebugger] Received page navigated message: {"result":{},"id":1}
[debug] [RemoteDebugger] Waiting for dom...
[debug] [RemoteDebugger] Page loaded, verifying whether ready
[debug] [RemoteDebugger] Not connected to an application. Ignoring page load
[debug] [W3C] Responding to client with driver.setUrl() result: {"protocol":"MJSONWP"}
[HTTP] <-- POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/url 200 1540 ms - 32
[HTTP]
[HTTP] --> POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/timeouts
[HTTP] {"type":"implicit","ms":10000}
[debug] [W3C] Bad parameters: BadParametersError: Parameters were incorrect. We wanted "W3C protocol expects any of script, pageLoad or implicit to be set" and you sent {"type":"implicit","ms":10000}
[HTTP] <-- POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/timeouts 400 2 ms - 4197
[HTTP]
[HTTP] --> POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/element
[HTTP] {"using":"xpath","value":"/html/body/header/div/ul/li[4]/a"}
[debug] [W3C] Calling AppiumDriver.findElement() with args: ["xpath","/html/body/header/div/ul/li[4]/a","faadf600-ae4c-4ffd-8fe0-c2e936282f89"]
[debug] [XCUITest] Executing command 'findElement'
[debug] [BaseDriver] Valid locator strategies for this request: xpath, id, name, class name, -ios predicate string, -ios class chain, accessibility id
[debug] [BaseDriver] Waiting up to 0 ms for condition
[debug] [RemoteDebugger] Executing 'find_element' atom in default context
[debug] [RemoteDebugger] Sending javascript command (function(){return function(){var k=this;functi...
[debug] [RemoteDebugger] Sending WebKit data: {"method":"Runtime.evaluate","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true,"expression":"(function(){return function(){var k=this;functi...
[debug] [RemoteDebugger] Webkit response timeout: 5000
[debug] [RemoteDebugger] Receiving WebKit data: '{"result":{"result":{"type":"string","value":"{"status":0,"value":null}"},"wasThrown":false},"id":2}'
[debug] [RemoteDebugger] Found handler for message '2'
[debug] [RemoteDebugger] Received result for atom 'find_element' execution: null
[HTTP] <-- POST /wd/hub/session/faadf600-ae4c-4ffd-8fe0-c2e936282f89/element 500 40 ms - 164
[HTTP]
[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.2","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.3","memoryCost":192000}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.6","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.8","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.9","memoryCost":192000}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.11","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.12","memoryCost":192000}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.14","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.16","memoryCost":1612800}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Canvas.canvasMemoryChanged","params":{"canvasId":"canvas:0.17","memoryCost":192000}}'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] WebKit debugger got a message for 'Canvas.canvasMemoryChanged' and have no handler, doing nothing.

[felyppers]

Any updates? Still happening with appium 1.8

[meizhang18]

Any updates? I am also hitting this.
I am using Xcode 9.2, iOS 11.2, Appium 1.7.1.
WDA launched then went to black screen.

[aryalakshmi]

Any updates on this issue?

[deepikashekar37]

I am also facing same issue.

Environment
Appium - 1.8.1
xcode - 9.4
real iOS device version - 11.4

**Appium logs **

Responding to client with driver.getContexts() result: ["NATIVE_APP","WEBVIEW_1"]
[HTTP] <-- GET /wd/hub/session/eee59416-4df8-4cd9-8986-41571c960409/contexts 200 9 ms - 36
[HTTP]
[HTTP] --> POST /wd/hub/session/eee59416-4df8-4cd9-8986-41571c960409/context
[HTTP] {"name":"WEBVIEW_1"}
[debug] [W3C] Calling AppiumDriver.setContext() with args: ["WEBVIEW_1","eee59416-4df8-4cd9-8986-41571c960409"]
[debug] [XCUITest] Executing command 'setContext'
[debug] [iOS] Attempting to set context to 'WEBVIEW_1'
[debug] [RemoteDebugger] WebKit debugger web socket connected to url: ws://localhost:27753/devtools/page/1
[debug] [RemoteDebugger] Starting to listen for JavaScript console
[debug] [RemoteDebugger] Sending WebKit data: {"method":"Console.enable","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true}}
[debug] [RemoteDebugger] Webkit response timeout: 50000
[debug] [RemoteDebugger] Receiving WebKit data: '{"result":{},"id":1}'
[debug] [RemoteDebugger] Found handler for message '1'
[debug] [RemoteDebugger] WebKit debugger got a message for 'Console.enable' and have no handler, doing nothing.
[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted
[W3C] Encountered internal error running command: TimeoutError: operation timed out
[W3C] at afterTimeout (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/release/timers.js:46:19)
[W3C] at Timeout.timeoutTimeout [as _onTimeout] (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/release/timers.js:76:13)
[W3C] at ontimeout (timers.js:466:11)
[W3C] at tryOnTimeout (timers.js:304:5)
[W3C] at Timer.listOnTimeout (timers.js:267:5)

Can anyone please help on this ?

[deepikashekar37]

Any updates on this issue?

[imurchie]

@deepikashekar37 Update to the latest Appium beta. There was an issue with Safari on the version you are using.

[suxiaowei]

is there solutions for this, on my opinions, seems ios automation with appium and wda can hardly be used, too many troubles. god

[deepikashekar37]

After upgrading Appium to 1.8.2 beta, i am not facing that issue.
Also Upgrade java client to 6.1.0.

@imurchie .. Thanks

[pmohanalatha]

After I increased the timeouts, the problem got solved. capabilities.setCapability("wdaLaunchTimeout",240000);
capabilities.setCapability("wdaConnectionTimeout",240000);

[sankaraspire]

MacOS 10.13.6
Xcode 10.1,
Appium 1.10.1(npm appium)
v11.8.0
Real Device (iPhone 7): iOS 12.1.2

Same issue facing on above environment.

Note: all the brews and npm packages are updated into latest

[ghost]

Hi @mykola-mokhnach
I have this error too with Appium 1.13.0, Xcode 10.2.1 and iOS 12.2 on Mac 10.14.4.
Anyone have any solution. Please update...

[kartikjain12]

Also Facing this issue with Appium 1.14 for mac.
This was happening very frequently in Appium 1.13. After upgrading its happen much less but quite a bit.

This following solution does not work for me.

capabilities.setCapability("wdaLaunchTimeout",240000);
capabilities.setCapability("wdaConnectionTimeout",240000);

Is there a way to know when this happens:

Connection to WDA timed out / recv failed: Operation not permitted 

I am using C# client.
I can resend the request to work around the issue.