The problem
I m using Selenium webdriver+Appium 1.6.3 + appium-xcuitest-driver + iPad Mini (iOS 10.2.)
Im getting this error frequently when launching an application on real device (ipad mini) “An unknown server-side error occurred while processing the command. Original error: operation timed out (WARNING: The server did not provide any stacktrace information)
Command duration or timeout: 5.02 seconds”, while executing the scripts. Some times it is executed smoothly without any timeout issue.
Eclipse Log
[TestNG] Running:
/private/var/folders/ym/twn5h8_n3yx1pm3d5ms8rs9c0000gn/T/testng-eclipse–95860488/testng-customsuite.xml
Test Step = Step 1 : Launch the required QA store.
Test Step = Platform Version: 10.2
Test Step = Platform Name: iOS
Test Step = Device Name: iPhone 6 Plus
Test Step = Device UDID: [spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]
Test Step = Browser Name : Safari
Test Step = Step-A : Appium Server Started
Test Step = Step-B: Browser is Navigating to 9969 FMS Store
close
Method = closeBrowser() = *Closing Browser
[Utils] Attempting to create /Users/vbsmac/Documents/eFollett_Automation/eFollett_IOS_Mobile/test-output/Default suite/Default test.xml
[Utils] Directory /Users/vbsmac/Documents/eFollett_Automation/eFollett_IOS_Mobile/test-output/Default suite exists: true
FAILED: EB_MergedCart
org.openqa.selenium.WebDriverException: An unknown server-side error occurred while processing the command. Original error: operation timed out (WARNING: The server did not provide any stacktrace information)
Command duration or timeout: 5.02 seconds
Build info: version: ‘2.51.0’, revision: ‘1af067dbcaedd7d2ab9af5151fc471d363d97193’, time: ‘2016-02-05 11:20:57’
System info: host: ‘test1.vserv-it.com’, ip: ‘[spoiler]192.168.1.243[/spoiler]’, os.name: ‘Mac OS X’, os.arch: ‘x86_64’, os.version: ‘10.12.2’, java.version: ‘1.8.0_60’
Driver info: io.appium.java_client.ios.IOSDriver
Capabilities [{networkConnectionEnabled=false, databaseEnabled=false, deviceName=Hitesh’s iPhone, platform=MAC, wdaLocalPort=9222, wdaLaunchTimeout=90000, safariIgnoreFraudWarning=true, platformVersion=10.2, safariAllowPopups=false, webStorageEnabled=false, locationContextEnabled=false, browserName=Safari, takesScreenshot=true, javascriptEnabled=true, autoWebview=true, platformName=iOS, udid=ea4059dcea980ac2ad67a31e088051749267b8b0}]
Session ID: 4a2a71fc-9a0c-415d-83df-4d0277456499
Appium Log
Last login: Fri Jan 20 09:46:50 on ttys002
test1:~ vbsmac$ appium -p 4727
[Appium] Welcome to Appium v1.6.3
[Appium] Non-default server args:
[Appium] port: 4727
[Appium] Appium REST http interface listener started on 0.0.0.0:4727
[HTTP] --> POST /wd/hub/session {“desiredCapabilities”:
[{“wdaLaunchTimeout”:“90000”,“safariIgnoreFraudWarning”:true,“platformVersion”:“10.2”,“safariAllowPopups”:false,“browserName”:“Safari”,“autoWebview”:“true”,“platformName”:“iOS”,“udid”:"[spoiler]ea4059dcea980ac2ad67a31e0[/spoiler]
88051749267b8b0",“deviceName”:“Hitesh’s iPhone”,“wdaLocalPort”:“9222”},null,null,null,null]
[Appium] Requested iOS support with version >= 10, using XCUITest driver instead of UIAutomation-based driver, since the latter is unsupported on iOS 10 and up.
[Appium] Creating new XCUITestDriver session
[Appium] Capabilities:
[Appium] wdaLaunchTimeout: ‘90000’
[Appium] safariIgnoreFraudWarning: true
[Appium] platformVersion: ‘10.2’
[Appium] safariAllowPopups: false
[Appium] browserName: ‘Safari’
[Appium] autoWebview: ‘true’
[Appium] platformName: ‘iOS’
[Appium] udid: ‘[spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]’
[Appium] deviceName: ‘Hitesh’s iPhone’
[Appium] wdaLocalPort: ‘9222’
[debug] [XCUITest] XCUITestDriver version: 2.4.2
[BaseDriver] Capability ‘autoWebview’ changed from string to boolean. This may cause unexpected behavior
[BaseDriver] Capability ‘wdaLocalPort’ changed from string (‘9222’) to integer (9222). This may cause unexpected behavior
[BaseDriver] The following capabilities were provided, but are not recognized by appium: wdaLaunchTimeout.
[BaseDriver] Session created with session id: 4a2a71fc-9a0c-415d-83df-4d0277456499
[debug] [XCUITest] Xcode version set to ‘8.2’
[debug] [XCUITest] iOS SDK Version set to ‘10.2’
[debug] [XCUITest] Available devices: [spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]
[debug] [XCUITest] Creating iDevice object with udid [spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]
[XCUITest] Determining device to run tests on: udid: ‘[spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]’, real device: true
[XCUITest] Safari test requested
[debug] [iOSLog] Attempting iOS device log capture via libimobiledevice idevicesyslog
[debug] [iOSLog] Found idevicesyslog: ‘/usr/local/bin/idevicesyslog’
[XCUITest] Setting up real device
[XCUITest] Using WDA path: ‘/usr/local/lib/node_modules/appium/node_modules/appium-xcuitest-driver/WebDriverAgent’
[XCUITest] Using WDA agent: ‘/usr/local/lib/node_modules/appium/node_modules/appium-xcuitest-driver/WebDriverAgent/WebDriverAgent.xcodeproj’
[XCUITest] Launching WebDriverAgent on the device
[debug] [XCUITest] Carthage found: /usr/local/bin/carthage
[debug] [XCUITest] Killing hanging processes
[debug] [XCUITest] Using real device logger ‘idevicesyslog’
[debug] [XCUITest] Beginning test with command 'xcodebuild build test -project /usr/local/lib/node_modules/appium/node_modules/appium-xcuitest-driver/WebDriverAgent/WebDriverAgent.xcodeproj -scheme
WebDriverAgentRunner -destination id=[spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler] -configuration Debug’ in directory ‘/usr/local/lib/node_modules/appium/node_modules/appium-xcuitest-driver/WebDriverAgent’
[debug] [XCUITest] Unable to get device time. Using local system time
[debug] [XCUITest] Output from idevicedate: Fri Jan 20 10:00:52 IST 2017
[XCUITest] Waiting for WebDriverAgent to start on device
[debug] [XCUITest] Log file for xcodebuild test: /Users/vbsmac/Library/Developer/Xcode/DerivedData/WebDriverAgent-brdadhpuduowllgivnnvuygpwhzy/Logs/Test/8B060F7B-80DD-411B-980F-317FF61A341C/Session-
WebDriverAgentRunner-2017-01-20_100056-grJUuG.log
[debug] [WebDriverAgent] Device: Jan 20 10:00:59 Hiteshs-iPhone XCTRunner[6541] : Running tests…
[debug] [WebDriverAgent] Device: Jan 20 10:01:00 Hiteshs-iPhone XCTRunner[6541] : Continuing to run tests in the background with task ID 1
[XCUITest] Detected that WebDriverAgent is running at url ‘http://192.168.1.247:8100’
[XCUITest] WebDriverAgent started at url ‘http://192.168.1.247:8100’
[debug] [XCUITest] Starting iproxy to forward traffic from local port 9222 to device port 8100 over USB
[debug] [JSONWP Proxy] Proxying [POST /session] to [POST http://localhost:9222/session] with body: {“desiredCapabilities”:{“bundleId”:“com.apple.mobilesafari”,“arguments”:["-
u",“http://appium.io”],“shouldWaitForQuiescence”:true}}
[debug] [JSONWP Proxy] Got response with status 200: {“value”:{“sessionId”:“E9679D1A-61A0-4FAF-BC83-D786275ED0F2”,“capabilities”:
{“device”:“iphone”,“browserName”:“Safari”,“sdkVersion”:“10.2”,“CFBundleIdentifier”:“com.apple.mobilesafari”}},“sessionId”:“E9679D1A-61A0-4FAF-BC83-D786275ED0F2”,“status”:0}
[debug] [XCUITest] Setting initial orientation to ‘PORTRAIT’
[debug] [JSONWP Proxy] Proxying [POST /orientation] to [POST http://localhost:9222/session/E9679D1A-61A0-4FAF-BC83-D786275ED0F2/orientation] with body: {“orientation”:“PORTRAIT”}
[debug] [JSONWP Proxy] Got response with status 200: {“value”:{},“sessionId”:“E9679D1A-61A0-4FAF-BC83-D786275ED0F2”,“status”:0}
[debug] [XCUITest] Waiting for initial webview
[debug] [iOS] Waiting for 14000 ms before navigating to view.
[debug] [iOS] Navigating to most recently opened webview
[debug] [iOS] Retrieving contexts and views
[debug] [iOS] Selecting by url: true (expected url: ‘http://appium.io’)
[debug] [RemoteDebugger] Getting WebKitRemoteDebugger pageArray: localhost, 27753
[debug] [RemoteDebugger] Sending request to: http://localhost:27753/json
[debug] [RemoteDebugger] Page element JSON: [{“devtoolsFrontendUrl”:"/devtools/devtools.html?ws=localhost:27753/devtools/page/2",“faviconUrl”:"",“thumbnailUrl”:"/thumb/http://appium.io/",“title”:"Appium: Mobile App
Automation Made Awesome.",“url”:“http://appium.io/",“webSocketDebuggerUrl”:“ws://localhost:27753/devtools/page/2”,“appId”:"PID:6547”}]
[debug] [iOS] Retrieving contexts and views
[debug] [iOS] Selecting by url: true (expected url: ‘http://appium.io’)
[debug] [RemoteDebugger] Getting WebKitRemoteDebugger pageArray: localhost, 27753
[debug] [RemoteDebugger] Sending request to: http://localhost:27753/json
[debug] [RemoteDebugger] Page element JSON: [{“devtoolsFrontendUrl”:"/devtools/devtools.html?ws=localhost:27753/devtools/page/2",“faviconUrl”:"",“thumbnailUrl”:"/thumb/http://appium.io/",“title”:"Appium: Mobile App
Automation Made Awesome.",“url”:“http://appium.io/",“webSocketDebuggerUrl”:“ws://localhost:27753/devtools/page/2”,“appId”:"PID:6547”}]
[debug] [iOS] Picking webview ‘WEBVIEW_2’
[debug] [iOS] Attempting to set context to ‘WEBVIEW_2’
[debug] [RemoteDebugger] WebKit debugger web socket connected to url: ws://localhost:27753/devtools/page/2
[debug] [RemoteDebugger] Unregistering from page readiness notifications
[Appium] New XCUITestDriver session created successfully, session 4a2a71fc-9a0c-415d-83df-4d0277456499 added to master session list
[debug] [MJSONWP] Responding to client with driver.createSession() result:
{“webStorageEnabled”:false,“locationContextEnabled”:false,“browserName”:“Safari”,“platform”:“MAC”,“javascriptEnabled”:true,“databaseEnabled”:false,“takesScreenshot”:true,“networkConnectionEnabled”:false,"wdaLaunchT
imeout":“90000”,“safariIgnoreFraudWarning”:true,“platformVersion”:“10.2”,“safariAllowPopups”:false,“autoWebview”:“true”,“platformName”:“iOS”,“udid”:"[spoiler]ea4059dcea980ac2ad67a31e088051749267b8b0[/spoiler]",“deviceName”:"Hites
h’s iPhone",“wdaLocalPort”:“9222”}
[HTTP] <-- POST /wd/hub/session 200 32432 ms - 530
[HTTP] --> POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts {“type”:“implicit”,“ms”:50000}
[debug] [MJSONWP] Calling AppiumDriver.timeouts() with args: [“implicit”,50000,“4a2a71fc-9a0c-415d-83df-4d0277456499”]
[debug] [XCUITest] Executing command ‘timeouts’
[debug] [BaseDriver] Set implicit wait to 50000ms
[debug] [MJSONWP] Responding to client with driver.timeouts() result: null
[HTTP] <-- POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts 200 11 ms - 76
[HTTP] --> POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts {“type”:“page load”,“ms”:9000000}
[debug] [MJSONWP] Calling AppiumDriver.timeouts() with args: [“page load”,9000000,“4a2a71fc-9a0c-415d-83df-4d0277456499”]
[debug] [XCUITest] Executing command ‘timeouts’
[debug] [iOS] Set page load timeout to 9000000ms
[debug] [MJSONWP] Responding to client with driver.timeouts() result: null
[HTTP] <-- POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts 200 4 ms - 76
[HTTP] --> POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts {“type”:“script”,“ms”:9000000}
[debug] [MJSONWP] Calling AppiumDriver.timeouts() with args: [“script”,9000000,“4a2a71fc-9a0c-415d-83df-4d0277456499”]
[debug] [XCUITest] Executing command ‘timeouts’
[debug] [iOS] Set async script timeout to 9000000ms
[debug] [MJSONWP] Responding to client with driver.timeouts() result: null
[HTTP] <-- POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/timeouts 200 5 ms - 76
[HTTP] --> POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/url {“url”:“http://URL”}
[debug] [MJSONWP] Calling AppiumDriver.setUrl() with args: [“http:URL”,“4a2a71fc-9a0c-415d-83df-4d0277456499”]
[debug] [XCUITest] Executing command ‘setUrl’
[debug] [iOS] Attempting to set url ‘http:URL’
[debug] [RemoteDebugger] Navigating to new URL: http://URL
[debug] [RemoteDebugger] Sending WebKit data: {“method”:“Page.navigate”,"…
[MJSONWP] Encountered internal error running command: TimeoutError: operation timed out
at afterTimeout (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/timers.js:16:15)
at Timeout.timeoutTimeout [as _onTimeout] (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/timers.js:59:9)
at ontimeout (timers.js:365:14)
at tryOnTimeout (timers.js:237:5)
at Timer.listOnTimeout (timers.js:207:5)
[HTTP] <-- POST /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499/url 500 5012 ms - 190
[HTTP] --> DELETE /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499 {}
[debug] [MJSONWP] Calling AppiumDriver.deleteSession() with args: [“4a2a71fc-9a0c-415d-83df-4d0277456499”]
[debug] [JSONWP Proxy] Proxying [DELETE /session/4a2a71fc-9a0c-415d-83df-4d0277456499] to [DELETE http://localhost:9222/session/E9679D1A-61A0-4FAF-BC83-D786275ED0F2] with no body
[debug] [JSONWP Proxy] Got response with status 200: “{\n “value” : {\n\n },\n “sessionId” : “59FFF210-1152-4693-B7E3-899EFD2B35BE”,\n “status” : 0\n}”
[XCUITest] Shutting down sub-processes
[XCUITest] Shutting down xcodebuild process (pid 19692)
[XCUITest] xcodebuild exited with code ‘null’ and signal ‘SIGTERM’
[XCUITest] Shutting down Logger process (pid 19697)
[XCUITest] System log exited with code ‘0’
[XCUITest] Shutting down iproxy process (pid 19707)
[XCUITest] iproxy exited with code ‘null’
[debug] [XCUITest] In a web session. Removing remote debugger
[debug] [RemoteDebugger] Disconnecting from WebKit remote debugger
[debug] [XCUITest] Running ios real device reset flow
[debug] [XCUITest] Resetting simulator
[debug] [iOSLog] Stopping iOS log capture
[Appium] Removing session 4a2a71fc-9a0c-415d-83df-4d0277456499 from our master session list
[debug] [MJSONWP] Received response: null
[debug] [MJSONWP] But deleting session, so not returning
[debug] [MJSONWP] Responding to client with driver.deleteSession() result: null
[HTTP] <-- DELETE /wd/hub/session/4a2a71fc-9a0c-415d-83df-4d0277456499 200 459 ms - 76
[debug] [RemoteDebugger] WebKit remote debugger socket disconnected