appiumlogs

appiumlogs.txt

[info] [Appium] Welcome to Appium v1.8.0
[info] [Appium] Non-default server args:
[info] [Appium]   address: 127.0.0.1
[info] [Appium] Appium REST http interface listener started on 127.0.0.1:4723[info] [HTTP] --> POST /wd/hub/session
[info] [HTTP] {"desiredCapabilities":{"deviceName":"'iPhone'","xcodeOrgId":"xxxxxxxxxx","udid":"xxxxxxxxxxxxxxxxxxc1e30f","webkitResponseTimeout":"180000","automationName":"Appium","autoWebview":"true","noReset":"true","useNewWDA":"true","clearSystemFiles":"True","xcodeSigningId":"iPhone Developer","newCommandTimeout":"1200","platformVersion":"11.1.2","wdaStartupRetryInterval":"1000","shouldUseSingletonTestManager":"false","platformName":"iOS","waitForQuiescence":"false","bundleId":"com.nokia.wifi"}}
[debug] [MJSONWP] Calling AppiumDriver.createSession() with args: [{"deviceName":"'iPhone'","xcodeOrgId":"xxxxxxxxxx","udid":"xxxxxxxxxxxxxxxxxxc1e30f","webkitResponseTimeout":"180000","automationName":"Appium","autoWebview":"true","noReset":"true","useNewWDA":"true","clearSystemFiles":"True","xcodeSigningId":"iPhone Developer","newCommandTimeout":"1200","platformVersion":"11.1.2","wdaStartupRetryInterval":"1000","shouldUseSingletonTestManager":"false","platformName":"iOS","waitForQuiescence":"false","bundleId":"com.nokia.wifi"},null,null]
[debug] [BaseDriver] Event 'newSessionRequested' logged at 1528348280235 (10:41:20 GMT+0530 (IST))
[info] [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.
[info] [Appium] Creating new XCUITestDriver (v2.79.3) session
[info] [Appium] Capabilities:
[info] [Appium]   deviceName: 'iPhone'
[info] [Appium]   xcodeOrgId: xxxxxxxxxx
[info] [Appium]   udid: xxxxxxxxxxxxxxxxxxc1e30f
[info] [Appium]   webkitResponseTimeout: 180000
[info] [Appium]   automationName: Appium
[info] [Appium]   autoWebview: true
[info] [Appium]   noReset: true
[info] [Appium]   useNewWDA: true
[info] [Appium]   clearSystemFiles: True
[info] [Appium]   xcodeSigningId: iPhone Developer
[info] [Appium]   newCommandTimeout: 1200
[info] [Appium]   platformVersion: 11.1.2
[info] [Appium]   wdaStartupRetryInterval: 1000
[info] [Appium]   shouldUseSingletonTestManager: false
[info] [Appium]   platformName: iOS
[info] [Appium]   waitForQuiescence: false
[info] [Appium]   bundleId: com.nokia.wifi
[debug] [BaseDriver] Creating session with MJSONWP desired capabilities: {"deviceName":"'iPhone'","x...
[warn] [BaseDriver] Capability 'autoWebview' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'noReset' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'useNewWDA' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'waitForQuiescence' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'shouldUseSingletonTestManager' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'clearSystemFiles' changed from string to boolean. This may cause unexpected behavior
[warn] [BaseDriver] Capability 'newCommandTimeout' changed from string ('1200') to integer (1200). This may cause unexpected behavior
[warn] [BaseDriver] Capability 'wdaStartupRetryInterval' changed from string ('1000') to integer (1000). This may cause unexpected behavior
[warn] [BaseDriver] Capability 'webkitResponseTimeout' changed from string ('180000') to integer (180000). This may cause unexpected behavior
[info] [BaseDriver] Session created with session id: 4434395e-aebc-4130-bab3-17d27c02f91c
[debug] [XCUITest] Current user: 'digitalhome'
[debug] [XCUITest] Xcode version set to '9.4' (tools v9.4.0.0.1.1526532315)
[debug] [XCUITest] iOS SDK Version set to '11.4'
[debug] [BaseDriver] Event 'xcodeDetailsRetrieved' logged at 1528348280330 (10:41:20 GMT+0530 (IST))[debug] [XCUITest] Available devices: xxxxxxxxxxxxxxxxxxc1e30f
[debug] [XCUITest] Creating iDevice object with udid 'xxxxxxxxxxxxxxxxxxc1e30f'
[info] [XCUITest] Determining device to run tests on: udid: 'xxxxxxxxxxxxxxxxxxc1e30f', real device: true
[debug] [BaseDriver] Event 'appConfigured' logged at 1528348280497 (10:41:20 GMT+0530 (IST))
[debug] [BaseDriver] Event 'resetStarted' logged at 1528348280498 (10:41:20 GMT+0530 (IST))
[debug] [XCUITest] Reset: fullReset not set. Leaving as is
[debug] [BaseDriver] Event 'resetComplete' logged at 1528348280498 (10:41:20 GMT+0530 (IST))
[debug] [iOSLog] Attempting iOS device log capture via libimobiledevice idevicesyslog
[debug] [iOSLog] Starting iOS device log capture with: 'idevicesyslog'[debug] [BaseDriver] Event 'logCaptureStarted' logged at 1528348280728 (10:41:20 GMT+0530 (IST))
[info] [XCUITest] Setting up real device
[info] [XCUITest] Using WDA path: '/Applications/Appium.app/Contents/Resources/app/node_modules/appium-xcuitest-driver/WebDriverAgent'
[info] [XCUITest] Using WDA agent: '/Applications/Appium.app/Contents/Resources/app/node_modules/appium-xcuitest-driver/WebDriverAgent/WebDriverAgent.xcodeproj'[debug] [XCUITest] No obsolete cached processes from previous WDA sessions listening on port 8100 have been found
[debug] [XCUITest] Capability 'useNewWDA' set to true, so uninstalling WDA before proceeding
[info] [XCUITest] Shutting down sub-processes
[debug] [XCUITest] Removing WDA application from device[debug] [BaseDriver] Event 'wdaUninstalled' logged at 1528348281469 (10:41:21 GMT+0530 (IST))
[debug] [BaseDriver] Event 'wdaStartAttempted' logged at 1528348281469 (10:41:21 GMT+0530 (IST))
[info] [XCUITest] Launching WebDriverAgent on the device
[debug] [XCUITest] Carthage found: '/usr/local/bin/carthage'
[debug] [XCUITest] Killing running processes 'xcodebuild.*xxxxxxxxxxxxxxxxxxc1e30f, iproxy 8100' for the device xxxxxxxxxxxxxxxxxxc1e30f...
[debug] [XCUITest] 'pgrep -nif xcodebuild.*xxxxxxxxxxxxxxxxxxc1e30f' didn't detect any matching processes. Return code: 1
[debug] [XCUITest] 'pgrep -nif iproxy 8100' didn't detect any matching processes. Return code: 1
[debug] [XCUITest] Starting iproxy to forward traffic from local port 8100 to device port 8100 over USB[debug] [XCUITest] Using Xcode 9.4, so fixing WDA codebase
[debug] [XCUITest] Generating xcode config file for orgId 'xxxxxxxxxx' and signingId 'iPhone Developer'
[debug] [XCUITest] Writing xcode config file to /var/folders/qs/8gk723dd315f6dwt9dr4ym440000gn/T/201857-542-6f9eq6.ahq05/appium-temp.xcconfig
[debug] [XCUITest] Using Xcode configuration file: '/var/folders/qs/8gk723dd315f6dwt9dr4ym440000gn/T/201857-542-6f9eq6.ahq05/appium-temp.xcconfig'
[debug] [XCUITest] Beginning test with command 'xcodebuild build-for-testing test-without-building -project /Applications/Appium.app/Contents/Resources/app/node_modules/appium-xcuitest-driver/WebDriverAgent/WebDriverAgent.xcodeproj -scheme WebDriverAgentRunner -destination id=xxxxxxxxxxxxxxxxxxc1e30f IPHONEOS_DEPLOYMENT_TARGET=11.1 -xcconfig /var/folders/qs/8gk723dd315f6dwt9dr4ym440000gn/T/201857-542-6f9eq6.ahq05/appium-temp.xcconfig' in directory '/Applications/Appium.app/Contents/Resources/app/node_modules/appium-xcuitest-driver/WebDriverAgent'
[debug] [XCUITest] Output from xcodebuild will not be logged. To change this, use 'showXcodeLog' desired capability[debug] [XCUITest] Waiting up to 60000ms for WebDriverAgent to start
[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [XCUITest] Log file for xcodebuild test: /var/folders/qs/8gk723dd315f6dwt9dr4ym440000gn/T/com.apple.dt.XCTest/IDETestRunSession-F95CBBEA-23DC-4C05-8E3D-0BDA9D0B403A/WebDriverAgentRunner-9B9D5024-68C2-4307-865B-FC4FED924BB7/Session-WebDriverAgentRunner-2018-06-07_104128-f5Kjy3.log[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:8100/status] with no body
[debug] [JSONWP Proxy] Got response with status 200: "{\n  \"value\" : {\n    \"state\" : \"success\",\n    \"os\" : {\n      \"name\" : \"iOS\",\n      \"version\" : \"11.1.2\",\n      \"sdkVersion\" : \"11.3\"\n    },\n    \"ios\" : {\n      \"simulatorVersion\" : \"11.1.2\",\n      \"ip\" : \"169.254.142.42\"\n    },\n    \"build\" : {\n      \"time\" : \"Jun  6 2018 20:41:54\"\n    }\n  },\n  \"sessionId\" : \"EC5BB806-9C34-482D-82D9-6142509FB167\",\n  \"status\" : 0\n}"
[debug] [XCUITest] WebDriverAgent running on ip '169.254.142.42'
[debug] [XCUITest] WebDriverAgent successfully started after 10796ms
[debug] [BaseDriver] Event 'wdaSessionAttempted' logged at 1528348297333 (10:41:37 GMT+0530 (IST))
[debug] [XCUITest] Sending createSession command to WDA
[debug] [JSONWP Proxy] Proxying [POST /session] to [POST http://localhost:8100/session] with body: {"desiredCapabilities":{"bundleId":"com.nokia.wifi","arguments":[],"environment":{},"shouldWaitForQuiescence":false,"shouldUseTestManagerForVisibilityDetection":false,"maxTypingFrequency":60,"shouldUseSingletonTestManager":false}}[debug] [JSONWP Proxy] Got response with status 200: {"value":{"sessionId":"7BC38FE6-35F3-4857-9391-57489183897A","capabilities":{"device":"iphone","browserName":"Nokia WiFi","sdkVersion":"11.1.2","CFBundleIdentifier":"com.nokia.wifi"}},"sessionId":"7BC38FE6-35F3-4857-9391-57489183897A","status":0}
[debug] [BaseDriver] Event 'wdaSessionStarted' logged at 1528348299117 (10:41:39 GMT+0530 (IST))
[debug] [XCUITest] Cannot find a match for DerivedData folder path from lsof. Trying to access logs
[debug] [BaseDriver] Event 'wdaStarted' logged at 1528348299250 (10:41:39 GMT+0530 (IST))
[info] [XCUITest] Skipping setting of the initial display orientation. Set the "orientation" capability to either "LANDSCAPE" or "PORTRAIT", if this is an undesired behavior.
[debug] [BaseDriver] Event 'orientationSet' logged at 1528348299250 (10:41:39 GMT+0530 (IST))
[debug] [XCUITest] Waiting for initial webview
[debug] [iOS] Waiting for 3000 ms before navigating to view.[debug] [iOS] Navigating to most recently opened webview
[debug] [iOS] Retrieving contexts and views
[debug] [iOS] Selecting by url: false 
[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://localhost:8080/var/containers/Bundle/Application/36FE7453-E23E-439B-8FC0-643AD469C7ED/Nokia%20WiFi.app/www/index.html","title":"Nokia WiFi","url":"http://localhost:8080/var/containers/Bundle/Application/36FE7453-E23E-439B-8FC0-643AD469C7ED/Nokia%20WiFi.app/www/index.html","webSocketDebuggerUrl":"ws://localhost:27753/devtools/page/2","appId":"PID:1518"}]
[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] 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: 180000[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] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"deviceready has not fired after 5 seconds.","type":"log","line":1138,"column":20,"url":"http://loc...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"Channel not fired: onPluginsReady","type":"log","line":1131,"column":24,"url":"http://localhost:80...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"Channel not fired: onCordovaReady","type":"log","line":1131,"column":24,"url":"http://localhost:80...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"Channel not fired: onDOMContentLoaded","type":"log","line":1131,"column":24,"url":"http://localhos...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"warning","text":"Ionic Native: deviceready did not fire within 5000ms. This can happen when plugins are in an i...'
[debug] [RemoteDebugger] Did not find handler for message[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"Ionic Native: deviceready event fired after 23668 ms","type":"log","line":1731,"column":28,"url":"...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"App requirements failed","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/con...'
[debug] [RemoteDebugger] Did not find handler for message[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"App Requirements failed","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/con...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"Wifi status","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/containers/Bund...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"iOS device. mobile data check not needed","type":"log","line":1731,"column":28,"url":"http://local...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"resolution passed","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/container...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"checkconnection failed","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/cont...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"log","text":"error in inital check","type":"log","line":1731,"column":28,"url":"http://localhost:8080/var/conta...'
[debug] [RemoteDebugger] Did not find handler for message
[debug] [RemoteDebugger] Receiving WebKit data: '{"method":"Console.messageAdded","params":{"message":{"source":"console-api","level":"error","text":"ERROR","type":"log","line":1328,"column":24,"url":"http://localhost:8080/var/containers/Bundle/A...'
[debug] [RemoteDebugger] Did not find handler for message[debug] [XCUITest] Connection to WDA timed out
[debug] [iProxy] recv failed: Operation not permitted[error] [XCUITest] TimeoutError: operation timed out
[error] [XCUITest]     at afterTimeout (/Applications/Appium.app/Contents/Resources/app/node_modules/bluebird/js/release/timers.js:46:19)
[error] [XCUITest]     at Timeout.timeoutTimeout [as _onTimeout] (/Applications/Appium.app/Contents/Resources/app/node_modules/bluebird/js/release/timers.js:76:13)
[error] [XCUITest]     at ontimeout (timers.js:475:11)
[error] [XCUITest]     at tryOnTimeout (timers.js:310:5)
[error] [XCUITest]     at Timer.listOnTimeout (timers.js:270:5)
[debug] [JSONWP Proxy] Proxying [DELETE /session/4434395e-aebc-4130-bab3-17d27c02f91c] to [DELETE http://localhost:8100/session/7BC38FE6-35F3-4857-9391-57489183897A] with no body[debug] [JSONWP Proxy] Got response with status 200: "{\n  \"value\" : {\n\n  },\n  \"sessionId\" : \"C32B5CA2-EB9D-4977-B5DE-5C07560A052D\",\n  \"status\" : 0\n}"
[info] [XCUITest] Shutting down sub-processes
[info] [XCUITest] Shutting down iproxy process (pid 23327)
[debug] [XCUITest] iproxy exited with code 'null'
[info] [XCUITest] Shutting down xcodebuild process (pid 23329)
[info] [XCUITest] xcodebuild exited with code 'null' and signal 'SIGTERM'
[debug] [XCUITest] Started background XCTest logs cleanup: find -E /private/var/folders -regex '.*/Session-WebDriverAgentRunner.*\.log$|.*/StandardOutputAndStandardError\.txt$' -type f -exec sh -c 'echo "" > "{}"' \;
[info] [XCUITest] Cleaning test logs in '/Users/digitalhome/Library/Developer/Xcode/DerivedData/WebDriverAgent-cvqckynzuuktkogfpkkkgyompmoj/Logs' folder
[debug] [iOS] Clearing log files
[debug] [iOS] Deleting '/Users/digitalhome/Library/Developer/Xcode/DerivedData/WebDriverAgent-cvqckynzuuktkogfpkkkgyompmoj/Logs'. Freeing 8.0K.
[debug] [iOS] Finished clearing log files
[debug] [XCUITest] In a web session. Removing remote debugger
[debug] [RemoteDebugger] Disconnecting from WebKit remote debugger
[debug] [iOSLog] Stopping iOS log capture
[debug] [RemoteDebugger] WebKit remote debugger socket disconnected
[debug] [BaseDriver] Event 'newSessionStarted' logged at 1528348482835 (10:44:42 GMT+0530 (IST))
[error] [MJSONWP] Encountered internal error running command: TimeoutError: operation timed out
[error] [MJSONWP]     at afterTimeout (/Applications/Appium.app/Contents/Resources/app/node_modules/bluebird/js/release/timers.js:46:19)
[error] [MJSONWP]     at Timeout.timeoutTimeout [as _onTimeout] (/Applications/Appium.app/Contents/Resources/app/node_modules/bluebird/js/release/timers.js:76:13)
[error] [MJSONWP]     at ontimeout (timers.js:475:11)
[error] [MJSONWP]     at tryOnTimeout (timers.js:310:5)
[error] [MJSONWP]     at Timer.listOnTimeout (timers.js:270:5)
[info] [HTTP] <-- POST /wd/hub/session 500 202602 ms - 156
[info] [HTTP]