Appium issue 10126 appium logs

gistfile1.txt

2018-02-14 12:47:46.2934 Appium starting for sessionId 8bad89c2-a96f-46aa-aad8-9088637be688
2018-02-14 12:47:48.3921 [Appium] Welcome to Appium v1.7.1
2018-02-14 12:47:48.3929 [Appium] Non-default server args:
2018-02-14 12:47:48.3929 [Appium]   address: 127.0.0.1
2018-02-14 12:47:48.3929 [Appium]   port: 23012
2018-02-14 12:47:48.3929 [Appium]   bootstrapPort: 23014
2018-02-14 12:47:48.3929 [Appium]   chromeDriverPort: 23013
2018-02-14 12:47:48.3929 [Appium]   chromedriverExecutable: chromedriver-2.34
2018-02-14 12:47:48.3929 [Appium]   tmpDir: /tmp/appium-instance
2018-02-14 12:47:48.3929 [Appium]   suppressKillServer: true
2018-02-14 12:47:48.4164 [Appium] Appium REST http interface listener started on 127.0.0.1:23012
2018-02-14 12:47:48.4164 Started.
2018-02-14 12:47:48.4172 Request: POST http://127.0.0.1:23012/wd/hub/session
2018-02-14 12:47:48.4382 [debug] [BaseDriver] Event 'newSessionRequested' logged at 1518641268438 (12:47:48 GMT-0800 (PST))
2018-02-14 12:47:48.4397 [Appium] Creating new AndroidDriver (v1.28.1) session
2018-02-14 12:47:48.4397 [Appium] Capabilities:
2018-02-14 12:47:48.4410 [Appium]   browserName: 'Chrome'
2018-02-14 12:47:48.4410 [Appium]   platformName: 'Android'
2018-02-14 12:47:48.4410 [Appium]   udid: '00da1f3821494955'
2018-02-14 12:47:48.4410 [Appium]   deviceName: 'LGE_00da1f3821494955'
2018-02-14 12:47:48.4410 [Appium]   showXcodeLog: true
2018-02-14 12:47:48.4410 [Appium]   newCommandTimeout: 0
2018-02-14 12:47:48.4493 [BaseDriver] Session created with session id: 538fde05-a875-43ca-a41d-50508b6c6d4e
2018-02-14 12:47:48.4493 [debug] [AndroidDriver] Getting Java version
2018-02-14 12:47:48.5588 [AndroidDriver] Java version is: 1.8.0_121
2018-02-14 12:47:48.5591 [AndroidDriver] We're going to run a Chrome-based session
2018-02-14 12:47:48.5591 [AndroidDriver] Chrome-type package and activity are com.android.chrome and com.google.android.apps.chrome.Main
2018-02-14 12:47:48.5614 [AndroidDriver] Retrieving device list
2018-02-14 12:47:48.5614 [debug] [ADB] Trying to find a connected android device
2018-02-14 12:47:48.5624 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:48.5809 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:48.5814 [AndroidDriver] Using device: 00da1f3821494955
2018-02-14 12:47:48.5822 [debug] [ADB] Setting device id to 00da1f3821494955
2018-02-14 12:47:48.5822 [AndroidDriver] App file was not listed, instead we're going to run com.android.chrome directly on the device
2018-02-14 12:47:48.5822 [debug] [AndroidDriver] Checking whether package is present on the device
2018-02-14 12:47:48.5830 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:48.6003 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:48.6024 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","list","packages","com.android.chrome"]
2018-02-14 12:47:49.5588 [AndroidDriver] Starting Android session
2018-02-14 12:47:49.5596 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","wait-for-device"]
2018-02-14 12:47:49.5772 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:49.5947 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:49.5949 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","echo","ping"]
2018-02-14 12:47:49.6334 [debug] [Logcat] Starting logcat capture
2018-02-14 12:47:49.6999 [debug] [AndroidDriver] Pushing settings apk to device...
2018-02-14 12:47:49.6999 [debug] [ADB] Uninstalling and re-installing 'io.appium.settings'
2018-02-14 12:47:49.7010 [debug] [ADB] Uninstalling io.appium.settings
2018-02-14 12:47:49.7010 [debug] [ADB] Getting install status for io.appium.settings
2018-02-14 12:47:49.7010 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:49.7248 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:49.7249 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","list","packages","io.appium.settings"]
2018-02-14 12:47:50.6405 [debug] [ADB] App is installed
2018-02-14 12:47:50.6405 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:50.6650 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:50.6650 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","am","force-stop","io.appium.settings"]
2018-02-14 12:47:50.7600 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","uninstall","io.appium.settings"]
2018-02-14 12:47:52.0803 [debug] [ADB] ADB command output: Success
2018-02-14 12:47:52.0803 [ADB] io.appium.settings was successfully uninstalled
2018-02-14 12:47:52.0803 [debug] [ADB] Getting install status for io.appium.settings
2018-02-14 12:47:52.0803 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:52.0992 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:52.0992 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","list","packages","io.appium.settings"]
2018-02-14 12:47:53.1561 [debug] [ADB] App is not installed
2018-02-14 12:47:53.1561 [debug] [ADB] App './appium/node_modules/appium/node_modules/io.appium.settings/app/build/outputs/apk/settings_apk-debug.apk' not installed. Installing
2018-02-14 12:47:53.1561 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","install","./appium/node_modules/appium/node_modules/io.appium.settings/app/build/outputs/apk/settings_apk-debug.apk"]
2018-02-14 12:47:54.7038 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:54.7231 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:54.7231 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","getprop","ro.build.version.sdk"]
2018-02-14 12:47:54.8016 [debug] [ADB] Current device property 'ro.build.version.sdk': 27
2018-02-14 12:47:54.8016 [debug] [ADB] Device API level: 27
2018-02-14 12:47:54.8022 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:54.8195 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:54.8195 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","dumpsys","package","io.appium.settings"]
2018-02-14 12:47:54.8901 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:54.9078 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:54.9081 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","dump","io.appium.settings"]
2018-02-14 12:47:56.3344 [debug] [ADB] Got the following command chunks to execute: pm,grant,io.appium.settings,android.permission.READ_PHONE_STATE,;,pm,grant,io.appium.settings,android.permission.WRITE_SETTINGS,;,pm,grant,io.appium.settings,android.permission.ACCESS_FINE_LOCATION,;,pm,grant,io.appium.settings,android.permission.ACCESS_COARSE_LOCATION,;,pm,grant,io.appium.settings,android.permission.ACCESS_MOCK_LOCATION,;,pm,grant,io.appium.settings,android.permission.SET_ANIMATION_SCALE,;
2018-02-14 12:47:56.3344 [debug] [ADB] Getting connected devices...
2018-02-14 12:47:56.3529 [debug] [ADB] 2 device(s) connected
2018-02-14 12:47:56.3531 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","grant","io.appium.settings","android.permission.READ_PHONE_STATE",";","pm","grant","io.appium.settings","android.permission.WRITE_SETTINGS",";","pm","grant","io.appium.settings","android.permission.ACCESS_FINE_LOCATION",";","pm","grant","io.appium.settings","android.permission.ACCESS_COARSE_LOCATION",";","pm","grant","io.appium.settings","android.permission.ACCESS_MOCK_LOCATION",";","pm","grant","io.appium.settings","android.permission.SET_ANIMATION_SCALE",";"]
2018-02-14 12:48:01.5016 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:01.5193 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:01.5193 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","ps"]
2018-02-14 12:48:01.7145 [debug] [ADB] Device API level: 27
2018-02-14 12:48:01.7145 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:01.7350 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:01.7350 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","am","start","-W","-n","io.appium.settings/.Settings","-a","android.intent.action.MAIN","-c","android.intent.category.LAUNCHER","-f","0x10200000"]
2018-02-14 12:48:02.4604 [debug] [ADB] Device API level: 27
2018-02-14 12:48:02.4604 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:02.4782 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:02.4782 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","appops","set","io.appium.settings","android:mock_location","allow"]
2018-02-14 12:48:02.5759 [debug] [AndroidDriver] Pushing unlock helper app to device...
2018-02-14 12:48:02.5760 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","install","./appium/node_modules/appium/node_modules/appium-unlock/bin/unlock_apk-debug.apk"]
2018-02-14 12:48:04.1558 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","install","./appium/node_modules/appium/node_modules/appium-unlock/bin/unlock_apk-debug.apk"]
2018-02-14 12:48:05.3816 [debug] [ADB] Application './appium/node_modules/appium/node_modules/appium-unlock/bin/unlock_apk-debug.apk' already installed. Continuing.
2018-02-14 12:48:05.3816 [ADB] Getting device platform version
2018-02-14 12:48:05.3820 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:05.4018 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:05.4021 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","getprop","ro.build.version.release"]
2018-02-14 12:48:05.4502 [debug] [ADB] Current device property 'ro.build.version.release': 8.1.0
2018-02-14 12:48:05.4502 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:05.4676 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:05.4676 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","wm","size"]
2018-02-14 12:48:06.3474 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:06.3656 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:06.3659 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","getprop","ro.product.model"]
2018-02-14 12:48:06.4160 [debug] [ADB] Current device property 'ro.product.model': Nexus 5X
2018-02-14 12:48:06.4160 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:06.4337 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:06.4340 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","getprop","ro.product.manufacturer"]
2018-02-14 12:48:06.4935 [debug] [ADB] Current device property 'ro.product.manufacturer': LGE
2018-02-14 12:48:06.4941 [AndroidDriver] No app sent in, not parsing package/activity
2018-02-14 12:48:06.4941 [debug] [AndroidDriver] No app capability. Assuming it is already on the device
2018-02-14 12:48:06.4941 [debug] [AndroidDriver] Running fast reset (stop and clear)
2018-02-14 12:48:06.4941 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:06.5126 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:06.5126 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","am","force-stop","com.android.chrome"]
2018-02-14 12:48:06.5984 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:06.6158 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:06.6160 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","pm","clear","com.android.chrome"]
2018-02-14 12:48:07.6092 [debug] [AndroidBootstrap] Watching for bootstrap disconnect
2018-02-14 12:48:07.6103 [debug] [ADB] Forwarding system: 23014 to device: 4724
2018-02-14 12:48:07.6103 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","forward","tcp:23014","tcp:4724"]
2018-02-14 12:48:07.6139 [debug] [UiAutomator] Starting UiAutomator
2018-02-14 12:48:07.6140 [debug] [UiAutomator] Moving to state 'starting'
2018-02-14 12:48:07.6140 [debug] [UiAutomator] Parsing uiautomator jar
2018-02-14 12:48:07.6140 [debug] [UiAutomator] Found jar name: 'AppiumBootstrap.jar'
2018-02-14 12:48:07.6140 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","push","./appium/node_modules/appium/node_modules/appium-android-bootstrap/bootstrap/bin/AppiumBootstrap.jar","/data/local/tmp/"]
2018-02-14 12:48:07.6430 [debug] [ADB] Attempting to kill all uiautomator processes
2018-02-14 12:48:07.6430 [debug] [ADB] Getting all processes with uiautomator
2018-02-14 12:48:07.6430 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:07.6611 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:07.6611 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","ps"]
2018-02-14 12:48:07.8582 [ADB] No uiautomator process found to kill, continuing...
2018-02-14 12:48:07.8582 [debug] [UiAutomator] Starting UIAutomator
2018-02-14 12:48:07.8582 [debug] [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","00da1f3821494955","shell","uiautomator","runtest","AppiumBootstrap.jar","-c","io.appium.android.bootstrap.Bootstrap","-e","pkg","com.android.chrome","-e","disableAndroidWatchers",false,"-e","acceptSslCerts",false]
2018-02-14 12:48:08.8687 [debug] [UiAutomator] Moving to state 'online'
2018-02-14 12:48:08.8716 [debug] [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Registered crash watchers.
2018-02-14 12:48:08.8728 [AndroidBootstrap] Android bootstrap socket is now connected
2018-02-14 12:48:08.8735 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:08.8763 [debug] [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Client connected
2018-02-14 12:48:08.8915 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:08.8915 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","dumpsys","window"]
2018-02-14 12:48:08.9557 [AndroidDriver] Screen already unlocked, doing nothing
2018-02-14 12:48:08.9561 [AndroidDriver] Starting a chrome-based browser session
2018-02-14 12:48:08.9590 [debug] [Chromedriver] Changed state to 'starting'
2018-02-14 12:48:08.9590 [Chromedriver] Set chromedriver binary as: chromedriver-2.34
2018-02-14 12:48:08.9603 [debug] [Chromedriver] Killing any old chromedrivers, running: pkill -15 -f "chromedriver-2.34.*--port=23013"
2018-02-14 12:48:08.9888 [Chromedriver] No old chromedrivers seemed to exist
2018-02-14 12:48:08.9889 [debug] [ADB] List forwarding ports
2018-02-14 12:48:08.9889 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","forward","--list"]
2018-02-14 12:48:09.0032 [Chromedriver] Spawning chromedriver with: chromedriver-2.34 --url-base=wd/hub --port=23013 --adb-port=5037 --verbose
2018-02-14 12:48:09.0239 [debug] [Chromedriver] [STDOUT] Starting ChromeDriver 2.34.522932 (4140ab217e1ca1bec0c4b4d1b148f3361eb3a03e) on port 23013
2018-02-14 12:48:09.0239 Only local connections are allowed.
2018-02-14 12:48:09.0265 [debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://127.0.0.1:23013/wd/hub/status] with no body
2018-02-14 12:48:09.0396 [debug] [JSONWP Proxy] Got response with status 200: "{\"sessionId\":\"\",\"status\":0,\"value\":{\"build\":{\"version\":\"alpha\"},\"os\":{\"arch\":\"x86_64\",\"name\":\"Mac OS X\",\"version\":\"10.12.6\"}}}"
2018-02-14 12:48:09.0401 [debug] [JSONWP Proxy] Proxying [POST /session] to [POST http://127.0.0.1:23013/wd/hub/session] with body: {"desiredCapabilities":{"chromeOptions":{"androidPackage":"com.android.chrome","androidDeviceSerial":"00da1f3821494955"}}}
2018-02-14 12:48:09.0432 stderr: [Chromedriver] [STDERR] [0.019][INFO]: COMMAND InitSession {
2018-02-14 12:48:09.0432 stderr:    "desiredCapabilities": {
2018-02-14 12:48:09.0432 stderr:       "chromeOptions": {
2018-02-14 12:48:09.0432 stderr:          "androidDeviceSerial": "00da1f3821494955",
2018-02-14 12:48:09.0432 stderr:          "androidPackage": "com.android.chrome"
2018-02-14 12:48:09.0432 stderr:       }
2018-02-14 12:48:09.0432 stderr:    }
2018-02-14 12:48:09.0432 stderr: }
2018-02-14 12:48:09.0432 stderr: [Chromedriver] [STDERR] [0.020][SEVERE]: bind() returned an error, errno=48: Address already in use (48)
2018-02-14 12:48:09.0554 stderr: [0.030][DEBUG]: Sending adb command: host:devices
2018-02-14 12:48:09.0554 stderr: [Chromedriver] [STDERR] [0.030][DEBUG]: Received adb response: 04ea83f6db8e36d0	device
2018-02-14 12:48:09.0554 stderr: 00da1f3821494955	device
2018-02-14 12:48:09.0554 stderr: [Chromedriver] [STDERR] [0.030][DEBUG]: Sending adb command: host:transport:00da1f3821494955|shell:pm path com.android.chrome
2018-02-14 12:48:09.9123 stderr: [Chromedriver] [STDERR] [0.889][DEBUG]: Received adb response: package:/data/app/com.android.chrome-NaVkxxmZzM0dUIA2uhEXwg==/base.apk
2018-02-14 12:48:09.9123 stderr: [Chromedriver] [STDERR] [0.889][DEBUG]: Sending adb command: host:transport:00da1f3821494955|shell:am set-debug-app --persistent com.android.chrome
2018-02-14 12:48:09.9823 stderr: [Chromedriver] [STDERR] [0.959][DEBUG]: Received adb response:
2018-02-14 12:48:09.9823 stderr: [Chromedriver] [STDERR] [0.959][DEBUG]: Sending adb command: host:transport:00da1f3821494955|shell:pm clear com.android.chrome
2018-02-14 12:48:10.9233 stderr: [Chromedriver] [STDERR] [1.900][DEBUG]: Received adb response: Success
2018-02-14 12:48:10.9233 stderr: [Chromedriver] [STDERR] [1.900][DEBUG]: Sending command line file: /data/local/chrome-command-line
2018-02-14 12:48:10.9282 stderr: [Chromedriver] [STDERR] [1.904][DEBUG]: Sending command line file: /data/local/tmp/chrome-command-line
2018-02-14 12:48:10.9351 stderr: [Chromedriver] [STDERR] [1.911][DEBUG]: Sending adb command: host:transport:00da1f3821494955|shell:am start -W -n com.android.chrome/com.google.android.apps.chrome.Main -d data:,
2018-02-14 12:48:12.4201 stderr: [Chromedriver] [STDERR] [3.396][DEBUG]: Received adb response: Starting: Intent { dat=data:, cmp=com.android.chrome/com.google.android.apps.chrome.Main }
2018-02-14 12:48:12.4201 bind() error filtered 383 times.
2018-02-14 12:48:12.4201 stderr: Status: ok
2018-02-14 12:48:12.4201 stderr: Activity: com.android.chrome/com.google.android.apps.chrome.Main
2018-02-14 12:48:12.4201 stderr: ThisTime: 1370
2018-02-14 12:48:12.4201 stderr: TotalTime: 1370
2018-02-14 12:48:12.4201 stderr: WaitTime: 1402
2018-02-14 12:48:12.4201 stderr: Complete
2018-02-14 12:48:12.4201 stderr: [Chromedriver] [STDERR] [3.396][DEBUG]: Sending adb command: host-serial:00da1f3821494955:forward:tcp:12004;localabstract:chrome_devtools_remote
2018-02-14 12:48:12.4201 stderr: [Chromedriver] [STDERR] [3.397][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.4303 stderr: [Chromedriver] [STDERR] [3.407][DEBUG]: DevTools request failed
2018-02-14 12:48:12.5455 stderr: [Chromedriver] [STDERR] [3.521][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.5474 stderr: [Chromedriver] [STDERR] [3.524][DEBUG]: DevTools request failed
2018-02-14 12:48:12.6690 stderr: [Chromedriver] [STDERR] [3.645][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.6716 stderr: [Chromedriver] [STDERR] [3.647][DEBUG]: DevTools request failed
2018-02-14 12:48:12.7794 stderr: [Chromedriver] [STDERR] [3.756][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.7818 stderr: [Chromedriver] [STDERR] [3.758][DEBUG]: DevTools request failed
2018-02-14 12:48:12.8329 stderr: [Chromedriver] [STDERR] [3.809][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.8362 stderr: [Chromedriver] [STDERR] [3.813][DEBUG]: DevTools request failed
2018-02-14 12:48:12.9600 stderr: [Chromedriver] [STDERR] [3.936][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:12.9623 stderr: [Chromedriver] [STDERR] [3.938][DEBUG]: DevTools request failed
2018-02-14 12:48:13.0717 stderr: [Chromedriver] [STDERR] [4.048][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.0744 stderr: [Chromedriver] [STDERR] [4.051][DEBUG]: DevTools request failed
2018-02-14 12:48:13.1935 stderr: [Chromedriver] [STDERR] [4.170][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.1959 stderr: [Chromedriver] [STDERR] [4.172][DEBUG]: DevTools request failed
2018-02-14 12:48:13.2699 stderr: [Chromedriver] [STDERR] [4.246][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.2716 stderr: [Chromedriver] [STDERR] [4.248][DEBUG]: DevTools request failed
2018-02-14 12:48:13.3659 stderr: [Chromedriver] [STDERR] [4.342][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.3680 stderr: [Chromedriver] [STDERR] [4.344][DEBUG]: DevTools request failed
2018-02-14 12:48:13.4776 stderr: [Chromedriver] [STDERR] [4.454][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.4810 stderr: [Chromedriver] [STDERR] [4.457][DEBUG]: DevTools request failed
2018-02-14 12:48:13.6045 stderr: [Chromedriver] [STDERR] [4.581][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.6070 stderr: [Chromedriver] [STDERR] [4.583][DEBUG]: DevTools request failed
2018-02-14 12:48:13.7214 stderr: [Chromedriver] [STDERR] [4.698][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.7244 stderr: [Chromedriver] [STDERR] [4.701][DEBUG]: DevTools request failed
2018-02-14 12:48:13.7849 stderr: [Chromedriver] [STDERR] [4.761][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.7869 stderr: [Chromedriver] [STDERR] [4.763][DEBUG]: DevTools request failed
2018-02-14 12:48:13.9038 stderr: [Chromedriver] [STDERR] [4.880][DEBUG]: DevTools request: http://localhost:12004/json/version
2018-02-14 12:48:13.9118 stderr: [Chromedriver] [STDERR] [4.888][DEBUG]: DevTools response: {
2018-02-14 12:48:13.9118 stderr:    "Android-Package": "com.android.chrome",
2018-02-14 12:48:13.9119 stderr:    "Browser": "Chrome/64.0.3282.137",
2018-02-14 12:48:13.9119 stderr:    "Protocol-Version": "1.2",
2018-02-14 12:48:13.9119 stderr:    "User-Agent": "Mozilla/5.0 (Linux; Android 8.1.0; Nexus 5X Build/OPM1.171019.011) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.137 Mobile Safari/537.36",
2018-02-14 12:48:13.9119 stderr:    "V8-Version": "6.4.388.41",
2018-02-14 12:48:13.9119 stderr:    "WebKit-Version": "537.36 (@c0e649dc6b7990e24daaee45fc1682e006f4f0ca)",
2018-02-14 12:48:13.9119 stderr:    "webSocketDebuggerUrl": "ws://localhost:12004/devtools/browser"
2018-02-14 12:48:13.9119 stderr: }
2018-02-14 12:48:13.9119 stderr: [Chromedriver] [STDERR] [4.888][DEBUG]: DevTools request: http://localhost:12004/json
2018-02-14 12:48:13.9155 stderr: [Chromedriver] [STDERR] [4.892][DEBUG]: DevTools response: [ {
2018-02-14 12:48:13.9155 stderr:    "description": "",
2018-02-14 12:48:13.9155 stderr:    "devtoolsFrontendUrl": "http://chrome-devtools-frontend.appspot.com/serve_rev/@c0e649dc6b7990e24daaee45fc1682e006f4f0ca/inspector.html?ws=localhost:12004/devtools/page/0",
2018-02-14 12:48:13.9155 stderr:    "id": "0",
2018-02-14 12:48:13.9155 stderr:    "title": "data:,",
2018-02-14 12:48:13.9155 stderr:    "type": "page",
2018-02-14 12:48:13.9155 stderr:    "url": "data:,",
2018-02-14 12:48:13.9155 stderr:    "webSocketDebuggerUrl": "ws://localhost:12004/devtools/page/0"
2018-02-14 12:48:13.9155 stderr: } ]
2018-02-14 12:48:13.9155 stderr: [Chromedriver] [STDERR] [4.892][DEBUG]: DevTools request: http://localhost:12004/json
2018-02-14 12:48:13.9282 stderr: [Chromedriver] [STDERR] [4.904][DEBUG]: DevTools response: [ {
2018-02-14 12:48:13.9282 stderr:    "description": "",
2018-02-14 12:48:13.9282 stderr:    "devtoolsFrontendUrl": "http://chrome-devtools-frontend.appspot.com/serve_rev/@c0e649dc6b7990e24daaee45fc1682e006f4f0ca/inspector.html?ws=localhost:12004/devtools/page/0",
2018-02-14 12:48:13.9282 stderr:    "id": "0",
2018-02-14 12:48:13.9282 stderr:    "title": "data:,",
2018-02-14 12:48:13.9282 stderr:    "type": "page",
2018-02-14 12:48:13.9282 stderr:    "url": "data:,",
2018-02-14 12:48:13.9282 stderr:    "webSocketDebuggerUrl": "ws://localhost:12004/devtools/page/0"
2018-02-14 12:48:13.9282 stderr: } ]
2018-02-14 12:48:13.9302 stderr: [Chromedriver] [STDERR] [4.906][INFO]: resolved localhost to ["::1","127.0.0.1"]
2018-02-14 12:48:13.9389 stderr: [Chromedriver] [STDERR] [4.915][DEBUG]: DEVTOOLS COMMAND Log.enable (id=1) {
2018-02-14 12:48:13.9389 stderr: 
2018-02-14 12:48:13.9389 stderr: }
2018-02-14 12:48:13.9389 stderr: [Chromedriver] [STDERR] [4.915][DEBUG]: DEVTOOLS COMMAND DOM.getDocument (id=2) {
2018-02-14 12:48:13.9389 stderr: 
2018-02-14 12:48:13.9389 stderr: }
2018-02-14 12:48:13.9389 stderr: [4.915][DEBUG]: DEVTOOLS COMMAND Runtime.enable (id=3) {
2018-02-14 12:48:13.9389 stderr: 
2018-02-14 12:48:13.9389 stderr: }
2018-02-14 12:48:13.9389 stderr: [4.915][DEBUG]: DEVTOOLS COMMAND Page.enable (id=4) {
2018-02-14 12:48:13.9389 stderr: 
2018-02-14 12:48:13.9389 stderr: }
2018-02-14 12:48:13.9389 stderr: [4.915][DEBUG]: DEVTOOLS COMMAND Page.enable (id=5) {
2018-02-14 12:48:13.9389 stderr: 
2018-02-14 12:48:13.9389 stderr: }
2018-02-14 12:48:13.9537 stderr: [Chromedriver] [STDERR] [4.930][DEBUG]: DEVTOOLS RESPONSE Log.enable (id=1) {
2018-02-14 12:48:13.9537 stderr: 
2018-02-14 12:48:13.9537 stderr: }
2018-02-14 12:48:13.9537 stderr: [Chromedriver] [STDERR] [4.930][DEBUG]: DEVTOOLS RESPONSE DOM.getDocument (id=2) {
2018-02-14 12:48:13.9537 stderr:    "root": {
2018-02-14 12:48:13.9539 stderr:       "backendNodeId": 1,
2018-02-14 12:48:13.9539 stderr:       "baseURL": "data:,",
2018-02-14 12:48:13.9539 stderr:       "childNodeCount": 1,
2018-02-14 12:48:13.9539 stderr:       "children": [ {
2018-02-14 12:48:13.9539 stderr:          "attributes": [  ],
2018-02-14 12:48:13.9539 stderr:          "backendNodeId": 2,
2018-02-14 12:48:13.9539 stderr:          "childNodeCount": 2,
2018-02-14 12:48:13.9539 stderr:          "children": [ {
2018-02-14 12:48:13.9539 stderr:             "attributes": [  ],
2018-02-14 12:48:13.9539 stderr:             "backendNodeId": 3,
2018-02-14 12:48:13.9539 stderr:             "childNodeCount": 0,
2018-02-14 12:48:13.9539 stderr:             "localName": "head",
2018-02-14 12:48:13.9539 stderr:             "nodeId": 3,
2018-02-14 12:48:13.9539 stderr:             "nodeName": "HEAD",
2018-02-14 12:48:13.9539 stderr:             "nodeType": 1,
2018-02-14 12:48:13.9539 stderr:             "nodeValue": "",
2018-02-14 12:48:13.9539 stderr:             "parentId": 2
2018-02-14 12:48:13.9539 stderr:          }, {
2018-02-14 12:48:13.9539 stderr:             "attributes": [  ],
2018-02-14 12:48:13.9539 stderr:             "backendNodeId": 4,
2018-02-14 12:48:13.9539 stderr:             "childNodeCount": 1,
2018-02-14 12:48:13.9539 stderr:             "localName": "body",
2018-02-14 12:48:13.9539 stderr:             "nodeId": 4,
2018-02-14 12:48:13.9539 stderr:             "nodeName": "BODY",
2018-02-14 12:48:13.9539 stderr:             "nodeType": 1,
2018-02-14 12:48:13.9539 stderr:             "nodeValue": "",
2018-02-14 12:48:13.9539 stderr:             "parentId": 2
2018-02-14 12:48:13.9539 stderr:          } ],
2018-02-14 12:48:13.9539 stderr:          "frameId": "(991C1139E4F6EA4B54DCFAD6A41E4C37)",
2018-02-14 12:48:13.9539 stderr:          "localName": "html",
2018-02-14 12:48:13.9539 stderr:          "nodeId": 2,
2018-02-14 12:48:13.9539 stderr:          "nodeName": "HTML",
2018-02-14 12:48:13.9539 stderr:          "nodeType": 1,
2018-02-14 12:48:13.9549 stderr:          "nodeValue": "",
2018-02-14 12:48:13.9549 stderr:          "parentId": 1
2018-02-14 12:48:13.9549 stderr:       } ],
2018-02-14 12:48:13.9549 stderr:       "documentURL": "data:,",
2018-02-14 12:48:13.9549 stderr:       "localName": "",
2018-02-14 12:48:13.9549 stderr:       "nodeId": 1,
2018-02-14 12:48:13.9549 stderr:       "nodeName": "#document",
2018-02-14 12:48:13.9549 stderr:       "nodeType": 9,
2018-02-14 12:48:13.9549 stderr:       "nodeValue": "",
2018-02-14 12:48:13.9549 stderr:       "xmlVersion": ""
2018-02-14 12:48:13.9549 stderr:    }
2018-02-14 12:48:13.9549 stderr: }
2018-02-14 12:48:13.9755 stderr: [Chromedriver] [STDERR] [4.952][DEBUG]: DEVTOOLS EVENT Runtime.executionContextCreated {
2018-02-14 12:48:13.9755 stderr:    "context": {
2018-02-14 12:48:13.9755 stderr:       "auxData": {
2018-02-14 12:48:13.9759 stderr:          "frameId": "(991C1139E4F6EA4B54DCFAD6A41E4C37)",
2018-02-14 12:48:13.9759 stderr:          "isDefault": true
2018-02-14 12:48:13.9759 stderr:       },
2018-02-14 12:48:13.9759 stderr:       "id": 1,
2018-02-14 12:48:13.9759 stderr:       "name": "",
2018-02-14 12:48:13.9759 stderr:       "origin": "://"
2018-02-14 12:48:13.9759 stderr:    }
2018-02-14 12:48:13.9759 stderr: }
2018-02-14 12:48:13.9804 stderr: [Chromedriver] [STDERR] [4.957][DEBUG]: DEVTOOLS RESPONSE Runtime.enable (id=3) {
2018-02-14 12:48:13.9804 stderr: 
2018-02-14 12:48:13.9804 stderr: }
2018-02-14 12:48:13.9804 stderr: [4.957][DEBUG]: DEVTOOLS RESPONSE Page.enable (id=4) {
2018-02-14 12:48:13.9804 stderr: 
2018-02-14 12:48:13.9804 stderr: }
2018-02-14 12:48:13.9804 stderr: [Chromedriver] [STDERR] [4.957][DEBUG]: DEVTOOLS RESPONSE Page.enable (id=5) {
2018-02-14 12:48:13.9804 stderr: 
2018-02-14 12:48:13.9804 stderr: }
2018-02-14 12:48:13.9804 stderr: [4.957][DEBUG]: DEVTOOLS COMMAND Page.enable (id=6) {
2018-02-14 12:48:13.9804 stderr: 
2018-02-14 12:48:13.9804 stderr: }
2018-02-14 12:48:13.9854 stderr: [Chromedriver] [STDERR] [4.962][DEBUG]: DEVTOOLS RESPONSE Page.enable (id=6) {
2018-02-14 12:48:13.9854 stderr: 
2018-02-14 12:48:13.9854 stderr: }
2018-02-14 12:48:13.9854 stderr: [Chromedriver] [STDERR] [4.962][DEBUG]: DEVTOOLS COMMAND Runtime.enable (id=7) {
2018-02-14 12:48:13.9854 stderr: 
2018-02-14 12:48:13.9854 stderr: }
2018-02-14 12:48:13.9940 stderr: [Chromedriver] [STDERR] [4.970][DEBUG]: DEVTOOLS RESPONSE Runtime.enable (id=7) {
2018-02-14 12:48:13.9940 stderr: 
2018-02-14 12:48:13.9940 stderr: }
2018-02-14 12:48:13.9940 stderr: [Chromedriver] [STDERR] [4.971][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=8) {
2018-02-14 12:48:13.9940 stderr:    "expression": "(function() { // Copyright (c) 2012 The Chromium Authors. All rights reserved.\n// Use of this source code is governed by a BSD-style license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
2018-02-14 12:48:13.9940 stderr:    "returnByValue": true
2018-02-14 12:48:13.9940 stderr: }
2018-02-14 12:48:14.0372 stderr: [Chromedriver] [STDERR] [5.013][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=8) {
2018-02-14 12:48:14.0372 stderr:    "result": {
2018-02-14 12:48:14.0372 stderr:       "type": "object",
2018-02-14 12:48:14.0372 stderr:       "value": {
2018-02-14 12:48:14.0372 stderr:          "status": 0,
2018-02-14 12:48:14.0372 stderr:          "value": 1
2018-02-14 12:48:14.0372 stderr:       }
2018-02-14 12:48:14.0372 stderr:    }
2018-02-14 12:48:14.0372 stderr: }
2018-02-14 12:48:14.0372 stderr: [Chromedriver] [STDERR] [5.013][INFO]: RESPONSE InitSession {
2018-02-14 12:48:14.0372 stderr:    "acceptSslCerts": true,
2018-02-14 12:48:14.0372 stderr:    "applicationCacheEnabled": false,
2018-02-14 12:48:14.0372 stderr:    "browserConnectionEnabled": false,
2018-02-14 12:48:14.0372 stderr:    "browserName": "chrome",
2018-02-14 12:48:14.0372 stderr:    "chrome": {
2018-02-14 12:48:14.0372 stderr:       "chromedriverVersion": "2.34.522932 (4140ab217e1ca1bec0c4b4d1b148f3361eb3a03e)"
2018-02-14 12:48:14.0372 stderr:    },
2018-02-14 12:48:14.0372 stderr:    "cssSelectorsEnabled": true,
2018-02-14 12:48:14.0379 stderr:    "databaseEnabled": false,
2018-02-14 12:48:14.0379 stderr:    "handlesAlerts": true,
2018-02-14 12:48:14.0379 stderr:    "hasTouchScreen": true,
2018-02-14 12:48:14.0379 stderr:    "javascriptEnabled": true,
2018-02-14 12:48:14.0379 stderr:    "locationContextEnabled": true,
2018-02-14 12:48:14.0379 stderr:    "mobileEmulationEnabled": false,
2018-02-14 12:48:14.0379 stderr:    "nativeEvents": true,
2018-02-14 12:48:14.0379 stderr:    "pageLoadStrategy": "normal",
2018-02-14 12:48:14.0379 stderr:    "platform": "ANDROID",
2018-02-14 12:48:14.0379 stderr:    "rotatable": false,
2018-02-14 12:48:14.0379 stderr:    "setWindowRect": false,
2018-02-14 12:48:14.0379 stderr:    "takesHeapSnapshot": true,
2018-02-14 12:48:14.0379 stderr:    "takesScreenshot": true,
2018-02-14 12:48:14.0379 [debug] [JSONWP Proxy] Got response with status 200: {"sessionId":"b7c946a8905a24783cbfb9da0d2826e6","status":0,"value":{"acceptSslCerts":true,"applicationCacheEnabled":false,"browserConnectionEnabled":false,"browserName":"chrome","chrome":{"chromedriverVersion":"2.34.522932 (4140ab217e1ca1bec0c4b4d1b148f3361eb3a03e)"},"cssSelectorsEnabled":true,"databaseEnabled":false,"handlesAlerts":true,"hasTouchScreen":true,"javascriptEnabled":true,"locationContextEnabled":true,"mobileEmulationEnabled":false,"nativeEvents":true,"pageLoadStrategy":"normal","platform":"ANDROID","rotatable":false,"setWindowRect":false,"takesHeapSnapshot":true,"takesScreenshot":true,"unexpectedAlertBehaviour":"","version":"64.0.3282.137","webStorageEnabled":true}}
2018-02-14 12:48:14.0379 stderr:    "~~~": "..."
2018-02-14 12:48:14.0379 stderr: }
2018-02-14 12:48:14.0379 [debug] [Chromedriver] Changed state to 'online'
2018-02-14 12:48:14.0405 [Appium] New AndroidDriver session created successfully, session 538fde05-a875-43ca-a41d-50508b6c6d4e added to master session list
2018-02-14 12:48:14.0405 [debug] [BaseDriver] Event 'newSessionStarted' logged at 1518641294040 (12:48:14 GMT-0800 (PST))
2018-02-14 12:48:14.0442 [HTTP] <-- POST /wd/hub/session 200 25606 ms - 1474
2018-02-14 12:48:14.0563 Request: GET http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context
2018-02-14 12:48:14.0588 [HTTP] --> GET /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context {}
2018-02-14 12:48:14.0607 [debug] [MJSONWP] Calling AppiumDriver.getCurrentContext() with args: ["538fde05-a875-43ca-a41d-50508b6c6d4e"]
2018-02-14 12:48:14.0618 [debug] [MJSONWP] Responding to client with driver.getCurrentContext() result: "CHROMIUM"
2018-02-14 12:48:14.0624 [HTTP] <-- GET /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context 200 4 ms - 82
2018-02-14 12:48:14.0629 Request: GET http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/contexts
2018-02-14 12:48:14.0640 [HTTP] --> GET /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/contexts {}
2018-02-14 12:48:14.0640 [debug] [MJSONWP] Calling AppiumDriver.getContexts() with args: ["538fde05-a875-43ca-a41d-50508b6c6d4e"]
2018-02-14 12:48:14.0651 [debug] [AndroidDriver] Available contexts: ["NATIVE_APP","CHROMIUM"]
2018-02-14 12:48:14.0651 [debug] [MJSONWP] Responding to client with driver.getContexts() result: ["NATIVE_APP","CHROMIUM"]
2018-02-14 12:48:14.0660 [HTTP] <-- GET /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/contexts 200 2 ms - 97
2018-02-14 12:48:14.0660 Request: POST http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context
2018-02-14 12:48:14.0674 [HTTP] --> POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context {"name":"CHROMIUM"}
2018-02-14 12:48:14.0674 [debug] [MJSONWP] Calling AppiumDriver.setContext() with args: ["CHROMIUM","538fde05-a875-43ca-a41d-50508b6c6d4e"]
2018-02-14 12:48:14.0683 [debug] [AndroidDriver] Available contexts: ["NATIVE_APP","CHROMIUM"]
2018-02-14 12:48:14.0683 [debug] [MJSONWP] Responding to client with driver.setContext() result: null
2018-02-14 12:48:14.0690 [HTTP] <-- POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context 200 1 ms - 76
2018-02-14 12:48:14.0700 Request: POST http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute
2018-02-14 12:48:14.0713 [HTTP] --> POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute {"script":<excluded>
2018-02-14 12:48:14.0713 [MJSONWP] Driver proxy active, passing request on via HTTP proxy
2018-02-14 12:48:14.0727 [debug] [JSONWP Proxy] Proxying [POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute] to [POST http://127.0.0.1:23013/wd/hub/session/b7c946a8905a24783cbfb9da0d2826e6/execute] with body: {"script":<excluded>
2018-02-14 12:48:14.0746 stderr: [Chromedriver] [STDERR] [5.051][INFO]: COMMAND ExecuteScript {
2018-02-14 12:48:14.0746 stderr:    "args": [  ],
2018-02-14 12:48:14.0746 stderr:    "script":<excluded>
2018-02-14 12:48:14.0746 stderr: }
2018-02-14 12:48:14.0746 stderr: [Chromedriver] [STDERR] [5.051][INFO]: Waiting for pending navigations...
2018-02-14 12:48:14.0749 stderr: [5.051][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=9) {
2018-02-14 12:48:14.0749 stderr:    "expression": "1"
2018-02-14 12:48:14.0749 stderr: }
2018-02-14 12:48:14.0815 stderr: [Chromedriver] [STDERR] [5.058][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=9) {
2018-02-14 12:48:14.0815 stderr:    "result": {
2018-02-14 12:48:14.0815 stderr:       "description": "1",
2018-02-14 12:48:14.0815 stderr:       "type": "number",
2018-02-14 12:48:14.0815 stderr:       "value": 1
2018-02-14 12:48:14.0815 stderr:    }
2018-02-14 12:48:14.0819 stderr: }
2018-02-14 12:48:14.0819 stderr: [Chromedriver] [STDERR] [5.058][DEBUG]: DEVTOOLS COMMAND DOM.getDocument (id=10) {
2018-02-14 12:48:14.0819 stderr: 
2018-02-14 12:48:14.0819 stderr: }
2018-02-14 12:48:14.0942 stderr: [Chromedriver] [STDERR] [5.067][DEBUG]: DEVTOOLS RESPONSE DOM.getDocument (id=10) {
2018-02-14 12:48:14.0942 stderr:    "root": {
2018-02-14 12:48:14.0942 stderr:       "backendNodeId": 1,
2018-02-14 12:48:14.0942 stderr:       "baseURL": "data:,",
2018-02-14 12:48:14.0942 stderr:       "childNodeCount": 1,
2018-02-14 12:48:14.0942 stderr:       "children": [ {
2018-02-14 12:48:14.0942 stderr:          "attributes": [  ],
2018-02-14 12:48:14.0942 stderr:          "backendNodeId": 2,
2018-02-14 12:48:14.0942 stderr:          "childNodeCount": 2,
2018-02-14 12:48:14.0942 stderr:          "children": [ {
2018-02-14 12:48:14.0942 stderr:             "attributes": [  ],
2018-02-14 12:48:14.0942 stderr:             "backendNodeId": 3,
2018-02-14 12:48:14.0942 stderr:             "childNodeCount": 0,
2018-02-14 12:48:14.0942 stderr:             "localName": "head",
2018-02-14 12:48:14.0942 stderr:             "nodeId": 7,
2018-02-14 12:48:14.0942 stderr:             "nodeName": "HEAD",
2018-02-14 12:48:14.0942 stderr:             "nodeType": 1,
2018-02-14 12:48:14.0949 stderr:             "nodeValue": "",
2018-02-14 12:48:14.0949 stderr:             "parentId": 6
2018-02-14 12:48:14.0949 stderr:          }, {
2018-02-14 12:48:14.0949 stderr:             "attributes": [  ],
2018-02-14 12:48:14.0949 stderr:             "backendNodeId": 4,
2018-02-14 12:48:14.0949 stderr:             "childNodeCount": 1,
2018-02-14 12:48:14.0949 stderr:             "localName": "body",
2018-02-14 12:48:14.0949 stderr:             "nodeId": 8,
2018-02-14 12:48:14.1298 stderr:             "nodeName": "BODY",
2018-02-14 12:48:14.1302 stderr:             "nodeType": 1,
2018-02-14 12:48:14.1302 stderr:             "nodeValue": "",
2018-02-14 12:48:14.1302 stderr:             "parentId": 6
2018-02-14 12:48:14.1302 stderr:          } ],
2018-02-14 12:48:14.1302 stderr:          "frameId": "(991C1139E4F6EA4B54DCFAD6A41E4C37)",
2018-02-14 12:48:14.1302 stderr:          "localName": "html",
2018-02-14 12:48:14.1302 stderr:          "nodeId": 6,
2018-02-14 12:48:14.1302 stderr:          "nodeName": "HTML",
2018-02-14 12:48:14.1302 stderr:          "nodeType": 1,
2018-02-14 12:48:14.1302 stderr:          "nodeValue": "",
2018-02-14 12:48:14.1302 stderr:          "parentId": 5
2018-02-14 12:48:14.1302 stderr:       } ],
2018-02-14 12:48:14.1302 stderr:       "documentURL": "data:,",
2018-02-14 12:48:14.1302 stderr:       "localName": "",
2018-02-14 12:48:14.1302 stderr:       "nodeId": 5,
2018-02-14 12:48:14.1309 stderr:       "nodeName": "#document",
2018-02-14 12:48:14.1309 stderr:       "nodeType": 9,
2018-02-14 12:48:14.1309 stderr:       "nodeValue": "",
2018-02-14 12:48:14.1309 stderr:       "xmlVersion": ""
2018-02-14 12:48:14.1309 stderr:    }
2018-02-14 12:48:14.1309 stderr: }
2018-02-14 12:48:14.1309 stderr: [Chromedriver] [STDERR] [5.067][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=11) {
2018-02-14 12:48:14.1309 stderr:    "expression": "var isLoaded = document.readyState == 'complete' ||    document.readyState == 'interactive';if (isLoaded) {  var frame = document.createElement('iframe');  frame.name = 'chromedriver dummy frame'; ..."
2018-02-14 12:48:14.1309 stderr: }
2018-02-14 12:48:14.1404 stderr: [Chromedriver] [STDERR] [5.117][DEBUG]: DEVTOOLS EVENT DOM.childNodeCountUpdated {
2018-02-14 12:48:14.1404 stderr:    "childNodeCount": 2,
2018-02-14 12:48:14.1404 stderr:    "nodeId": 8
2018-02-14 12:48:14.1404 stderr: }
2018-02-14 12:48:14.1404 stderr: [Chromedriver] [STDERR] [5.117][DEBUG]: DEVTOOLS EVENT Page.frameAttached {
2018-02-14 12:48:14.1404 stderr:    "frameId": "(7B25D6538953B1FEC89CA055E3E8705)",
2018-02-14 12:48:14.1404 stderr:    "parentFrameId": "(991C1139E4F6EA4B54DCFAD6A41E4C37)",
2018-02-14 12:48:14.1404 stderr:    "stack": {
2018-02-14 12:48:14.1404 stderr:       "callFrames": [ {
2018-02-14 12:48:14.1404 stderr:          "columnNumber": 240,
2018-02-14 12:48:14.1404 stderr:          "functionName": "",
2018-02-14 12:48:14.1404 stderr:          "lineNumber": 0,
2018-02-14 12:48:14.1409 stderr:          "scriptId": "22",
2018-02-14 12:48:14.1409 stderr:          "url": ""
2018-02-14 12:48:14.1409 stderr:       } ]
2018-02-14 12:48:14.1409 stderr:    }
2018-02-14 12:48:14.1409 stderr: }
2018-02-14 12:48:14.1409 stderr: [5.117][DEBUG]: DEVTOOLS EVENT Page.frameStartedLoading {
2018-02-14 12:48:14.1409 stderr:    "frameId": "(7B25D6538953B1FEC89CA055E3E8705)"
2018-02-14 12:48:14.1409 stderr: }
2018-02-14 12:48:14.1409 stderr: [5.117][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=12) {
2018-02-14 12:48:14.1409 stderr:    "expression": "document.readyState"
2018-02-14 12:48:14.1409 stderr: }
2018-02-14 12:48:14.1409 stderr: [5.117][DEBUG]: DEVTOOLS EVENT Page.frameNavigated {
2018-02-14 12:48:14.1409 stderr:    "frame": {
2018-02-14 12:48:14.1409 stderr:       "id": "(7B25D6538953B1FEC89CA055E3E8705)",
2018-02-14 12:48:14.1409 stderr:       "loaderId": "(94B2844EDE42910CB1A49EC7FAF16478)",
2018-02-14 12:48:14.1409 stderr:       "mimeType": "text/html",
2018-02-14 12:48:14.1409 stderr:       "name": "chromedriver dummy frame",
2018-02-14 12:48:14.1409 stderr:       "parentId": "(991C1139E4F6EA4B54DCFAD6A41E4C37)",
2018-02-14 12:48:14.1409 stderr:       "securityOrigin": "://",
2018-02-14 12:48:14.1409 stderr:       "url": "about:blank"
2018-02-14 12:48:14.1409 stderr:    }
2018-02-14 12:48:14.1409 stderr: }
2018-02-14 12:48:14.1454 stderr: [Chromedriver] [STDERR] [5.122][DEBUG]: DEVTOOLS EVENT Runtime.executionContextCreated {
2018-02-14 12:48:14.1454 stderr:    "context": {
2018-02-14 12:48:14.1454 stderr:       "auxData": {
2018-02-14 12:48:14.1454 stderr:          "frameId": "(7B25D6538953B1FEC89CA055E3E8705)",
2018-02-14 12:48:14.1454 stderr:          "isDefault": true
2018-02-14 12:48:14.1454 stderr:       },
2018-02-14 12:48:14.1454 stderr:       "id": 2,
2018-02-14 12:48:14.1454 stderr:       "name": "",
2018-02-14 12:48:14.1454 stderr:       "origin": "://"
2018-02-14 12:48:14.1454 stderr:    }
2018-02-14 12:48:14.1454 stderr: }
2018-02-14 12:48:14.1467 stderr: [Chromedriver] [STDERR] [5.122][DEBUG]: DEVTOOLS EVENT Page.frameStoppedLoading {
2018-02-14 12:48:14.1467 stderr:    "frameId": "(7B25D6538953B1FEC89CA055E3E8705)"
2018-02-14 12:48:14.1467 stderr: }
2018-02-14 12:48:14.1467 stderr: [5.122][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=11) {
2018-02-14 12:48:14.1467 stderr:    "result": {
2018-02-14 12:48:14.1469 stderr:       "description": "1",
2018-02-14 12:48:14.1469 stderr:       "type": "number",
2018-02-14 12:48:14.1469 stderr:       "value": 1
2018-02-14 12:48:14.1469 stderr:    }
2018-02-14 12:48:14.1469 stderr: }
2018-02-14 12:48:14.4743 [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_RESULT: shortMsg=java.lang.StackOverflowError
2018-02-14 12:48:14.4781 [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_RESULT: longMsg=stack size 1037KB
2018-02-14 12:48:14.4781 [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_CODE: 0
2018-02-14 12:48:14.5150 stderr: [UiAutomator] UiAutomator exited unexpectedly with code 255, signal null
2018-02-14 12:48:14.5150 [debug] [UiAutomator] Moving to state 'stopped'
2018-02-14 12:48:14.5284 [debug] [AndroidDriver] Shutting down Android driver
2018-02-14 12:48:14.5284 [Appium] Closing session, cause was 'UiAUtomator shut down unexpectedly'
2018-02-14 12:48:14.5284 [Appium] Removing session 538fde05-a875-43ca-a41d-50508b6c6d4e from our master session list
2018-02-14 12:48:14.5291 [debug] [AndroidDriver] Stopping chromedriver for context CHROMIUM
2018-02-14 12:48:14.5291 [debug] [Chromedriver] Changed state to 'stopping'
2018-02-14 12:48:14.5291 [debug] [JSONWP Proxy] Proxying [DELETE /] to [DELETE http://127.0.0.1:23013/wd/hub/session/b7c946a8905a24783cbfb9da0d2826e6] with no body
2018-02-14 12:48:14.5665 stderr: [Chromedriver] [STDERR] [5.543][DEBUG]: DEVTOOLS EVENT DOM.childNodeCountUpdated {
2018-02-14 12:48:14.5665 stderr:    "childNodeCount": 1,
2018-02-14 12:48:14.5665 stderr:    "nodeId": 8
2018-02-14 12:48:14.5665 stderr: }
2018-02-14 12:48:14.5665 stderr: [Chromedriver] [STDERR] [5.543][DEBUG]: DEVTOOLS EVENT Runtime.executionContextDestroyed {
2018-02-14 12:48:14.5665 stderr:    "executionContextId": 2
2018-02-14 12:48:14.5665 stderr: }
2018-02-14 12:48:14.5665 stderr: [5.543][DEBUG]: DEVTOOLS EVENT Page.frameDetached {
2018-02-14 12:48:14.5669 stderr:    "frameId": "(7B25D6538953B1FEC89CA055E3E8705)"
2018-02-14 12:48:14.5669 stderr: }
2018-02-14 12:48:14.5669 stderr: [5.543][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=12) {
2018-02-14 12:48:14.5669 stderr:    "result": {
2018-02-14 12:48:14.5669 stderr:       "type": "string",
2018-02-14 12:48:14.5669 stderr:       "value": "complete"
2018-02-14 12:48:14.5669 stderr:    }
2018-02-14 12:48:14.5669 stderr: }
2018-02-14 12:48:14.5669 stderr: [5.543][INFO]: Done waiting for pending navigations. Status: ok
2018-02-14 12:48:14.5669 stderr: [Chromedriver] [STDERR] [5.544][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=13) {
2018-02-14 12:48:14.5669 stderr:    "expression": "(function() { // Copyright (c) 2012 The Chromium Authors. All rights reserved.\n// Use of this source code is governed by a BSD-style license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
2018-02-14 12:48:14.5669 stderr:    "returnByValue": true
2018-02-14 12:48:14.5669 stderr: }
2018-02-14 12:48:14.5862 stderr: [Chromedriver] [STDERR] [5.562][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=13) {
2018-02-14 12:48:14.5862 stderr:    "result": {
2018-02-14 12:48:14.5862 stderr:       "type": "object",
2018-02-14 12:48:14.5862 stderr:       "value": {
2018-02-14 12:48:14.5862 stderr:          "status": 0,
2018-02-14 12:48:14.5862 stderr:          "value": null
2018-02-14 12:48:14.5862 stderr:       }
2018-02-14 12:48:14.5862 stderr:    }
2018-02-14 12:48:14.5862 stderr: }
2018-02-14 12:48:14.5862 stderr: [Chromedriver] [STDERR] [5.562][INFO]: Waiting for pending navigations...
2018-02-14 12:48:14.5862 stderr: [5.562][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate (id=14) {
2018-02-14 12:48:14.5862 stderr:    "expression": "1"
2018-02-14 12:48:14.5862 stderr: }
2018-02-14 12:48:14.5907 stderr: [Chromedriver] [STDERR] [5.567][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate (id=14) {
2018-02-14 12:48:14.5907 stderr:    "result": {
2018-02-14 12:48:14.5907 stderr:       "description": "1",
2018-02-14 12:48:14.5907 stderr:       "type": "number",
2018-02-14 12:48:14.5907 stderr:       "value": 1
2018-02-14 12:48:14.5907 stderr:    }
2018-02-14 12:48:14.5909 stderr: }
2018-02-14 12:48:14.5909 stderr: [Chromedriver] [STDERR] [5.567][INFO]: Done waiting for pending navigations. Status: ok
2018-02-14 12:48:14.5909 stderr: [5.567][INFO]: RESPONSE ExecuteScript null
2018-02-14 12:48:14.5909 stderr: [5.567][INFO]: COMMAND Quit {
2018-02-14 12:48:14.5909 stderr: 
2018-02-14 12:48:14.5909 stderr: }
2018-02-14 12:48:14.5909 stderr: [5.567][DEBUG]: Sending adb command: host:transport:00da1f3821494955|shell:am force-stop com.android.chrome
2018-02-14 12:48:14.5909 [debug] [JSONWP Proxy] Got response with status 200: {"sessionId":"b7c946a8905a24783cbfb9da0d2826e6","status":0,"value":null}
2018-02-14 12:48:14.5909 [JSONWP Proxy] Replacing sessionId b7c946a8905a24783cbfb9da0d2826e6 with 538fde05-a875-43ca-a41d-50508b6c6d4e
2018-02-14 12:48:14.5922 [HTTP] <-- POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute 200 521 ms - 76
2018-02-14 12:48:14.5922 Request: POST http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute
2018-02-14 12:48:14.5936 [HTTP] --> POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute {"script":<excluded>
2018-02-14 12:48:14.5945 [HTTP] <-- POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/execute 404 1 ms - 131
2018-02-14 12:48:14.5952 Request: POST http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context
2018-02-14 12:48:14.5960 [HTTP] --> POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context {"name":"NATIVE_APP"}
2018-02-14 12:48:14.5969 [HTTP] <-- POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context 404 1 ms - 131
2018-02-14 12:48:14.5980 Request: POST http://127.0.0.1:23012/wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context
2018-02-14 12:48:14.5999 [HTTP] --> POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context {"name":"CHROMIUM"}
2018-02-14 12:48:14.6004 [HTTP] <-- POST /wd/hub/session/538fde05-a875-43ca-a41d-50508b6c6d4e/context 404 0 ms - 131
2018-02-14 12:48:14.7076 stderr: [Chromedriver] [STDERR] [5.684][DEBUG]: Received adb response:
2018-02-14 12:48:14.7076 stderr: [Chromedriver] [STDERR] [5.684][INFO]: RESPONSE Quit
2018-02-14 12:48:14.7076 stderr: [5.684][DEBUG]: Log type 'driver' lost 384 entries on destruction
2018-02-14 12:48:14.7076 stderr: [5.684][DEBUG]: Log type 'browser' lost 0 entries on destruction
2018-02-14 12:48:14.7083 [debug] [JSONWP Proxy] Got response with status 200: "{\"sessionId\":\"b7c946a8905a24783cbfb9da0d2826e6\",\"status\":0,\"value\":null}"
2018-02-14 12:48:14.7108 [debug] [Chromedriver] Changed state to 'stopped'
2018-02-14 12:48:14.7110 [debug] [ADB] Pressing the HOME button
2018-02-14 12:48:14.7110 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:14.7295 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:14.7295 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","input","keyevent",3]
2018-02-14 12:48:15.9954 [AndroidBootstrap] Cannot shut down Android bootstrap; it has already shut down
2018-02-14 12:48:15.9954 [debug] [Logcat] Stopping logcat capture
2018-02-14 12:48:15.9970 [debug] [ADB] Getting connected devices...
2018-02-14 12:48:16.0148 [debug] [ADB] 2 device(s) connected
2018-02-14 12:48:16.0148 [debug] [ADB] Running 'adb' with args: ["-P",5037,"-s","00da1f3821494955","shell","am","force-stop","io.appium.unlock"]
2018-02-14 12:48:16.1109 [debug] [AndroidDriver] Not cleaning generated files. Add `clearSystemFiles` capability if wanted.