yejianfengblue/appium-server.log

## appium-server.log
# test case 2.1
# mjpegServerPort = 12345, mjpegScreenshotUrl port is 12345

2021-03-22 21:45:28:313 [HTTP] Request idempotency key: c64b41cf-9201-4343-8585-5a15f098488d
2021-03-22 21:45:28:320 [HTTP] --> POST /wd/hub/session
2021-03-22 21:45:28:320 [HTTP] {"capabilities":{"firstMatch":[{"platformName":"Android","appium:automationName":"uiautomator2","appium:udid":"m4:5555","appium:mjpegServerPort":12345,"appium:mjpegScreenshotUrl":"http://m4:12345","appium:newCommandTimeout":600,"appium:noReset":true}]},"desiredCapabilities":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true}}
2021-03-22 21:45:28:321 [W3C] Calling AppiumDriver.createSession() with args: [{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true},null,{"firstMatch":[{"platformName":"Android","appium:automationName":"uiautomator2","appium:udid":"m4:5555","appium:mjpegServerPort":12345,"appium:mjpegScreenshotUrl":"http://m4:12345","appium:newCommandTimeout":600,"appium:noReset":true}]}]
2021-03-22 21:45:28:321 [BaseDriver] Event 'newSessionRequested' logged at 1616420728321 (21:45:28 GMT+0800 (China Standard Time))
2021-03-22 21:45:28:333 [Appium] Appium v1.20.2 creating new AndroidUiautomator2Driver (v1.61.2) session
2021-03-22 21:45:28:336 [BaseDriver] W3C capabilities and MJSONWP desired capabilities were provided
2021-03-22 21:45:28:337 [BaseDriver] Creating session with W3C capabilities: {
2021-03-22 21:45:28:337 [BaseDriver]   "alwaysMatch": {
2021-03-22 21:45:28:337 [BaseDriver]     "platformName": "Android",
2021-03-22 21:45:28:337 [BaseDriver]     "appium:automationName": "uiautomator2",
2021-03-22 21:45:28:337 [BaseDriver]     "appium:udid": "m4:5555",
2021-03-22 21:45:28:338 [BaseDriver]     "appium:mjpegServerPort": 12345,
2021-03-22 21:45:28:338 [BaseDriver]     "appium:mjpegScreenshotUrl": "http://m4:12345",
2021-03-22 21:45:28:338 [BaseDriver]     "appium:newCommandTimeout": 600,
2021-03-22 21:45:28:338 [BaseDriver]     "appium:noReset": true
2021-03-22 21:45:28:338 [BaseDriver]   },
2021-03-22 21:45:28:338 [BaseDriver]   "firstMatch": [
2021-03-22 21:45:28:339 [BaseDriver]     {}
2021-03-22 21:45:28:339 [BaseDriver]   ]
2021-03-22 21:45:28:339 [BaseDriver] }
2021-03-22 21:45:28:353 [BaseDriver] Session created with session id: ce20dea4-d2b1-4bac-9995-e1d016e6a09e
2021-03-22 21:45:28:353 [UiAutomator2] Neither 'app' nor 'appPackage' was set. Starting UiAutomator2 without the target application
2021-03-22 21:45:28:358 [ADB] Using 'adb' from '/home/k/software/android-sdk/platform-tools/adb'
2021-03-22 21:45:28:359 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 start-server'
2021-03-22 21:45:28:369 [AndroidDriver] Retrieving device list
2021-03-22 21:45:28:369 [ADB] Trying to find a connected android device
2021-03-22 21:45:28:369 [ADB] Getting connected devices
2021-03-22 21:45:28:378 [ADB] Connected devices: [{"udid":"m4:5555","state":"device"},{"udid":"n2:5555","state":"device"},{"udid":"r2:5555","state":"device"},{"udid":"r3:5555","state":"device"},{"udid":"r5:5555","state":"device"}]
2021-03-22 21:45:28:378 [AndroidDriver] Using device: m4:5555
2021-03-22 21:45:28:379 [ADB] Using 'adb' from '/home/k/software/android-sdk/platform-tools/adb'
2021-03-22 21:45:28:379 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 start-server'
2021-03-22 21:45:28:387 [ADB] Setting device id to m4:5555
2021-03-22 21:45:28:388 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell getprop ro.build.version.sdk'
2021-03-22 21:45:28:501 [ADB] Current device property 'ro.build.version.sdk': 23
2021-03-22 21:45:28:501 [ADB] Device API level: 23
2021-03-22 21:45:28:501 [AndroidDriver] No app sent in, not parsing package/activity
2021-03-22 21:45:28:502 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 wait-for-device'
2021-03-22 21:45:28:511 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell echo ping'
2021-03-22 21:45:28:560 [AndroidDriver] Pushing settings apk to device...
2021-03-22 21:45:28:561 [ADB] Getting install status for io.appium.settings
2021-03-22 21:45:28:561 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.settings'
2021-03-22 21:45:28:650 [ADB] 'io.appium.settings' is installed
2021-03-22 21:45:28:651 [ADB] Getting package info for 'io.appium.settings'
2021-03-22 21:45:28:651 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.settings'
2021-03-22 21:45:28:736 [ADB] The version name of the installed 'io.appium.settings' is greater or equal to the application version name ('3.2.1' >= '3.2.1')
2021-03-22 21:45:28:737 [ADB] There is no need to install/upgrade '/home/k/.npm-global/lib/node_modules/appium/node_modules/io.appium.settings/apks/settings_apk-debug.apk'
2021-03-22 21:45:28:737 [ADB] Getting IDs of all 'io.appium.settings' processes
2021-03-22 21:45:28:737 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4\:5555 shell 'pgrep --help; echo $?''
2021-03-22 21:45:28:795 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell pgrep -f \(\[\[:blank:\]\]\|\^\)io\.appium\.settings\(\[\[:blank:\]\]\|\$\)'
2021-03-22 21:45:28:898 [AndroidDriver] io.appium.settings is already running. There is no need to reset its permissions.
2021-03-22 21:45:28:899 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell appops set io.appium.settings android:mock_location allow'
2021-03-22 21:45:30:195 [Logcat] Starting logs capture with command: /home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4\:5555 logcat -v threadtime
2021-03-22 21:45:30:265 [UiAutomator2] Forwarding UiAutomator2 Server port 6790 to local port 8205
2021-03-22 21:45:30:265 [ADB] Forwarding system: 8205 to device: 6790
2021-03-22 21:45:30:266 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward tcp:8205 tcp:6790'
2021-03-22 21:45:30:279 [ADB] Forwarding system: 12345 to device: 7810
2021-03-22 21:45:30:279 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward tcp:12345 tcp:7810'
2021-03-22 21:45:30:297 [ADB] Getting install status for io.appium.uiautomator2.server
2021-03-22 21:45:30:298 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server'
2021-03-22 21:45:30:375 [ADB] 'io.appium.uiautomator2.server' is installed
2021-03-22 21:45:30:375 [ADB] Getting package info for 'io.appium.uiautomator2.server'
2021-03-22 21:45:30:376 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server'
2021-03-22 21:45:30:447 [ADB] The version name of the installed 'io.appium.uiautomator2.server' is greater or equal to the application version name ('4.17.4' >= '4.17.4')
2021-03-22 21:45:30:447 [UiAutomator2] io.appium.uiautomator2.server installation state: sameVersionInstalled
2021-03-22 21:45:30:448 [ADB] Checking app cert for /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk
2021-03-22 21:45:30:452 [ADB] Using 'apksigner.jar' from '/home/k/software/android-sdk/apksigner.jar'
2021-03-22 21:45:30:453 [ADB] Starting apksigner: /lib/jvm/java-11-openjdk/bin/java -Xmx1024M -Xss1m -jar /home/k/software/android-sdk/apksigner.jar verify --print-certs /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk
2021-03-22 21:45:30:696 [ADB] apksigner stdout: Signer #1 certificate DN: EMAILADDRESS=android@android.com, CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
2021-03-22 21:45:30:696 [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
2021-03-22 21:45:30:696 [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
2021-03-22 21:45:30:696 [ADB]
2021-03-22 21:45:30:697 [ADB] sha256 hash did match for 'appium-uiautomator2-server-v4.17.4.apk'
2021-03-22 21:45:30:697 [ADB] '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk' is signed with the default certificate
2021-03-22 21:45:30:697 [ADB] Getting install status for io.appium.uiautomator2.server.test
2021-03-22 21:45:30:697 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server.test'
2021-03-22 21:45:30:756 [ADB] 'io.appium.uiautomator2.server.test' is installed
2021-03-22 21:45:30:756 [ADB] Checking app cert for /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk
2021-03-22 21:45:30:756 [ADB] Starting apksigner: /lib/jvm/java-11-openjdk/bin/java -Xmx1024M -Xss1m -jar /home/k/software/android-sdk/apksigner.jar verify --print-certs /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk
2021-03-22 21:45:30:956 [ADB] apksigner stdout: Signer #1 certificate DN: EMAILADDRESS=android@android.com, CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
2021-03-22 21:45:30:956 [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
2021-03-22 21:45:30:956 [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
2021-03-22 21:45:30:956 [ADB]
2021-03-22 21:45:30:957 [ADB] sha256 hash did match for 'appium-uiautomator2-server-debug-androidTest.apk'
2021-03-22 21:45:30:957 [ADB] '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk' is signed with the default certificate
2021-03-22 21:45:30:957 [UiAutomator2] Server packages are not going to be (re)installed
2021-03-22 21:45:30:960 [UiAutomator2] Waiting up to 30000ms for services to be available
2021-03-22 21:45:30:960 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell pm list instrumentation'
2021-03-22 21:45:32:000 [UiAutomator2] Instrumentation target 'io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner' is available
2021-03-22 21:45:32:003 [ADB] Adding packages ["io.appium.settings","io.appium.uiautomator2.server","io.appium.uiautomator2.server.test"] to Doze whitelist
2021-03-22 21:45:32:003 [ADB] Got the following command chunks to execute: [["dumpsys","deviceidle","whitelist","+io.appium.settings",";","dumpsys","deviceidle","whitelist","+io.appium.uiautomator2.server",";","dumpsys","deviceidle","whitelist","+io.appium.uiautomator2.server.test",";"]]
2021-03-22 21:45:32:004 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys deviceidle whitelist +io.appium.settings ; dumpsys deviceidle whitelist +io.appium.uiautomator2.server ; dumpsys deviceidle whitelist +io.appium.uiautomator2.server.test ;'
2021-03-22 21:45:32:122 [UiAutomator2] No app capability. Assuming it is already on the device
2021-03-22 21:45:32:122 [UiAutomator2] Performing shallow cleanup of automation leftovers
2021-03-22 21:45:32:138 [UiAutomator2] No obsolete sessions have been detected (socket hang up)
2021-03-22 21:45:32:138 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell am force-stop io.appium.uiautomator2.server.test'
2021-03-22 21:45:33:199 [UiAutomator2] Starting UIAutomator2 server 4.17.4
2021-03-22 21:45:33:200 [UiAutomator2] Using UIAutomator2 server from '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk' and test from '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk'
2021-03-22 21:45:33:200 [UiAutomator2] Waiting up to 30000ms for UiAutomator2 to be online...
2021-03-22 21:45:33:200 [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","m4:5555","shell","am","instrument","-w","io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner"]
2021-03-22 21:45:33:212 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:45:33:213 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:45:33:218 [WD Proxy] socket hang up
2021-03-22 21:45:34:221 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:45:34:222 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:45:34:226 [WD Proxy] socket hang up
2021-03-22 21:45:34:571 [Instrumentation] io.appium.uiautomator2.server.test.AppiumUiAutomator2Server:
2021-03-22 21:45:35:226 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:45:35:227 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:45:35:233 [WD Proxy] socket hang up
2021-03-22 21:45:36:235 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:45:36:235 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:45:36:352 [WD Proxy] Got response with status 200: {"sessionId":"None","value":{"message":"UiAutomator2 Server is ready to accept commands","ready":true}}
2021-03-22 21:45:36:352 [UiAutomator2] The initialization of the instrumentation process took 3152ms
2021-03-22 21:45:36:353 [WD Proxy] Matched '/session' to command name 'createSession'
2021-03-22 21:45:36:353 [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:8205/wd/hub/session] with body: {"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555"}],"alwaysMatch":{}}}
2021-03-22 21:45:36:424 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":{"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555"}],"alwaysMatch":{}},"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb"}}
2021-03-22 21:45:36:424 [WD Proxy] Determined the downstream protocol as 'W3C'
2021-03-22 21:45:36:447 [WD Proxy] Proxying [GET /appium/device/info] to [GET http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb/appium/device/info] with no body
2021-03-22 21:45:36:498 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":{"androidId":"4cea0ae73854c9e9","apiVersion":"23","bluetooth":{"state":"OFF"},"brand":"Xiaomi","carrierName":"","displayDensity":480,"locale":"zh_CN","manufacturer":"Xiaomi","model":"MI 4LTE","networks":[{"capabilities":{"SSID":null,"linkDownBandwidthKbps":1048576,"linkUpstreamBandwidthKbps":1048576,"networkCapabilities":"NET_CAPABILITY_NOT_RESTRICTED,NET_CAPABILITY_NOT_VPN,NET_CAPABILITY_INTERNET,NET_CAPABILITY_TRUSTED,NET_CAPABILITY_VALIDATED","signalStrength":-54,"transportTypes":"TRANSPORT_WIFI"},"detailedState":"CONNECTED","extraInfo":"\"Blue5_5G\"","isAvailable":true,"isConnected":true,"isFailover":false,"isRoaming":false,"state":"CONNECTED","subtype":0,"subtypeName":"","type":1,"typeName":"WIFI"}],"platformVersion":"6.0.1","realDisplaySize":"1080x1920","timeZone":"Asia/Shanghai"}}
2021-03-22 21:45:36:498 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys window'
2021-03-22 21:45:36:596 [AndroidDriver] Screen already unlocked, doing nothing
2021-03-22 21:45:36:599 [WD Proxy] Proxying [GET /appium/device/pixel_ratio] to [GET http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb/appium/device/pixel_ratio] with no body
2021-03-22 21:45:36:609 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":3}
2021-03-22 21:45:36:612 [WD Proxy] Matched '/appium/device/system_bars' to command name 'getSystemBars'
2021-03-22 21:45:36:612 [WD Proxy] Proxying [GET /appium/device/system_bars] to [GET http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb/appium/device/system_bars] with no body
2021-03-22 21:45:36:655 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":{"statusBar":60}}
2021-03-22 21:45:36:656 [WD Proxy] Matched '/window/current/size' to command name 'getWindowSize'
2021-03-22 21:45:36:657 [WD Proxy] Proxying [GET /window/current/size] to [GET http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb/window/current/size] with no body
2021-03-22 21:45:36:668 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":{"height":1920,"width":1080}}
2021-03-22 21:45:36:669 [UiAutomator2] Starting MJPEG stream reading URL: 'http://m4:12345'
2021-03-22 21:45:36:679 [Support] Error getting MJpeg screenshot chunk: connect ECONNREFUSED 192.168.31.140:12345
2021-03-22 21:45:36:679 [Appium] New AndroidUiautomator2Driver session created successfully, session ce20dea4-d2b1-4bac-9995-e1d016e6a09e added to master session list
2021-03-22 21:45:36:680 [BaseDriver] Event 'newSessionStarted' logged at 1616420736680 (21:45:36 GMT+0800 (China Standard Time))
2021-03-22 21:45:36:681 [W3C (ce20dea4)] Cached the protocol value 'W3C' for the new session ce20dea4-d2b1-4bac-9995-e1d016e6a09e
2021-03-22 21:45:36:682 [W3C (ce20dea4)] Responding to client with driver.createSession() result: {"capabilities":{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:12345","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555","deviceApiLevel":23,"platformVersion":"6.0.1","deviceScreenSize":"1080x1920","deviceScreenDensity":480,"deviceModel":"MI 4LTE","deviceManufacturer":"Xiaomi","pixelRatio":3,"statBarHeight":60,"viewportRect":{"left":0,"top":60,"width":1080,"height":1860}}}
2021-03-22 21:45:36:683 [HTTP] <-- POST /wd/hub/session 200 8363 ms - 936
2021-03-22 21:45:36:684 [HTTP]


2021-03-22 21:47:48:057 [HTTP] --> GET /wd/hub/session/ce20dea4-d2b1-4bac-9995-e1d016e6a09e/appium/settings
2021-03-22 21:47:48:057 [HTTP] {}
2021-03-22 21:47:48:065 [W3C (ce20dea4)] Calling AppiumDriver.getSettings() with args: ["ce20dea4-d2b1-4bac-9995-e1d016e6a09e"]
2021-03-22 21:47:48:067 [WD Proxy] Matched '/appium/settings' to command name 'getSettings'
2021-03-22 21:47:48:067 [WD Proxy] Proxying [GET /appium/settings] to [GET http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb/appium/settings] with no body
2021-03-22 21:47:48:148 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":{"keyInjectionDelay":0,"mjpegScalingFactor":50,"trackScrollEvents":true,"normalizeTagNames":false,"useResourcesForOrientationDetection":false,"mjpegServerScreenshotQuality":50,"wakeLockTimeout":86267545,"waitForSelectorTimeout":10000,"mjpegServerPort":12345,"ignoreUnimportantViews":false,"simpleBoundsCalculation":false,"shutdownOnPowerDisconnect":true,"scrollAcknowledgmentTimeout":200,"mjpegServerFramerate":10,"elementResponseAttributes":"","enableMultiWindows":false,"actionAcknowledgmentTimeout":3000,"serverPort":6790,"waitForIdleTimeout":10000,"allowInvisibleElements":false,"enableNotificationListener":true,"mjpegBilinearFiltering":false,"shouldUseCompactResponses":true}}
2021-03-22 21:47:48:149 [W3C (ce20dea4)] Responding to client with driver.getSettings() result: {"imageMatchThreshold":0.4,"fixImageFindScreenshotDims":true,"fixImageTemplateSize":false,"fixImageTemplateScale":false,"defaultImageTemplateScale":1,"checkForImageElementStaleness":true,"autoUpdateImageElementPosition":false,"imageElementTapStrategy":"w3cActions","getMatchedImageResult":false,"ignoreUnimportantViews":false,"allowInvisibleElements":false,"keyInjectionDelay":0,"mjpegScalingFactor":50,"trackScrollEvents":true,"normalizeTagNames":false,"useResourcesForOrientationDetection":false,"mjpegServerScreenshotQuality":50,"wakeLockTimeout":86267545,"waitForSelectorTimeout":10000,"mjpegServerPort":12345,"simpleBoundsCalculation":false,"shutdownOnPowerDisconnect":true,"scrollAcknowledgmentTimeout":200,"mjpegServerFramerate":10,"elementResponseAttributes":"","enableMultiWindows":false,"actionAcknowledgmentTimeout":3000,"serverPort":6790,"waitForIdleTimeout":10000,"enableNotificationListener":true,"mjpegBilinearFiltering":false,"shouldUseCompactResponses":true}
2021-03-22 21:47:48:150 [HTTP] <-- GET /wd/hub/session/ce20dea4-d2b1-4bac-9995-e1d016e6a09e/appium/settings 200 93 ms - 985
2021-03-22 21:47:48:150 [HTTP]


2021-03-22 21:48:32:361 [HTTP] --> DELETE /wd/hub/session/ce20dea4-d2b1-4bac-9995-e1d016e6a09e
2021-03-22 21:48:32:362 [HTTP] {}
2021-03-22 21:48:32:362 [W3C (ce20dea4)] Calling AppiumDriver.deleteSession() with args: ["ce20dea4-d2b1-4bac-9995-e1d016e6a09e"]
2021-03-22 21:48:32:362 [BaseDriver] Event 'quitSessionRequested' logged at 1616420912362 (21:48:32 GMT+0800 (China Standard Time))
2021-03-22 21:48:32:363 [Appium] Removing session ce20dea4-d2b1-4bac-9995-e1d016e6a09e from our master session list
2021-03-22 21:48:32:363 [UiAutomator2] Deleting UiAutomator2 session
2021-03-22 21:48:32:363 [UiAutomator2] Deleting UiAutomator2 server session
2021-03-22 21:48:32:364 [WD Proxy] Matched '/' to command name 'deleteSession'
2021-03-22 21:48:32:364 [WD Proxy] Proxying [DELETE /] to [DELETE http://127.0.0.1:8205/wd/hub/session/c495986b-d776-4a48-968a-085b5bc8f7eb] with no body
2021-03-22 21:48:32:401 [WD Proxy] Got response with status 200: {"sessionId":"c495986b-d776-4a48-968a-085b5bc8f7eb","value":null}
2021-03-22 21:48:32:402 [Logcat] Stopping logcat capture
2021-03-22 21:48:32:403 [ADB] Removing forwarded port socket connection: 8205
2021-03-22 21:48:32:403 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:8205'
2021-03-22 21:48:32:415 [ADB] Removing forwarded port socket connection: 12345
2021-03-22 21:48:32:416 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:12345'
2021-03-22 21:48:32:426 [UiAutomator2] Closing MJPEG stream
2021-03-22 21:48:32:427 [Appium] Had trouble ending session ce20dea4-d2b1-4bac-9995-e1d016e6a09e: Cannot read property 'unpipe' of null
2021-03-22 21:48:32:427 [BaseDriver] Event 'quitSessionFinished' logged at 1616420912427 (21:48:32 GMT+0800 (China Standard Time))
2021-03-22 21:48:32:501 [W3C (ce20dea4)] Encountered internal error running command: TypeError: Cannot read property 'unpipe' of null
2021-03-22 21:48:32:501 [W3C (ce20dea4)]     at MJpegStream.stop (/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-support/lib/mjpeg.js:164:25)
2021-03-22 21:48:32:501 [W3C (ce20dea4)]     at AndroidUiautomator2Driver.deleteSession (/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-driver/lib/driver.js:670:24)
2021-03-22 21:48:32:501 [W3C (ce20dea4)]     at AppiumDriver.deleteSession (/home/k/.npm-global/lib/node_modules/appium/lib/appium.js:490:16)
2021-03-22 21:48:32:511 [HTTP] <-- DELETE /wd/hub/session/ce20dea4-d2b1-4bac-9995-e1d016e6a09e 500 150 ms - 589
2021-03-22 21:48:32:511 [HTTP]
2021-03-22 21:48:32:856 [Instrumentation] .
2021-03-22 21:48:34:024 [Instrumentation] Time: 178.277
2021-03-22 21:48:34:024 [Instrumentation]
2021-03-22 21:48:34:024 [Instrumentation] OK (1 test)
2021-03-22 21:48:34:229 [Instrumentation] The process has exited with code 0


# test case 2.2
# mjpegServerPort = 12345, mjpegScreenshotUrl port is 7810

2021-03-22 21:50:57:801 [HTTP] Request idempotency key: f67aaf98-c4bc-450c-a675-7e595a27588a
2021-03-22 21:50:57:802 [HTTP] --> POST /wd/hub/session
2021-03-22 21:50:57:802 [HTTP] {"capabilities":{"firstMatch":[{"platformName":"Android","appium:automationName":"uiautomator2","appium:udid":"m4:5555","appium:mjpegServerPort":12345,"appium:mjpegScreenshotUrl":"http://m4:7810","appium:newCommandTimeout":600,"appium:noReset":true}]},"desiredCapabilities":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true}}
2021-03-22 21:50:57:802 [W3C] Calling AppiumDriver.createSession() with args: [{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true},null,{"firstMatch":[{"platformName":"Android","appium:automationName":"uiautomator2","appium:udid":"m4:5555","appium:mjpegServerPort":12345,"appium:mjpegScreenshotUrl":"http://m4:7810","appium:newCommandTimeout":600,"appium:noReset":true}]}]
2021-03-22 21:50:57:802 [BaseDriver] Event 'newSessionRequested' logged at 1616421057802 (21:50:57 GMT+0800 (China Standard Time))
2021-03-22 21:50:57:804 [Appium] Appium v1.20.2 creating new AndroidUiautomator2Driver (v1.61.2) session
2021-03-22 21:50:57:804 [BaseDriver] W3C capabilities and MJSONWP desired capabilities were provided
2021-03-22 21:50:57:805 [BaseDriver] Creating session with W3C capabilities: {
2021-03-22 21:50:57:805 [BaseDriver]   "alwaysMatch": {
2021-03-22 21:50:57:805 [BaseDriver]     "platformName": "Android",
2021-03-22 21:50:57:805 [BaseDriver]     "appium:automationName": "uiautomator2",
2021-03-22 21:50:57:805 [BaseDriver]     "appium:udid": "m4:5555",
2021-03-22 21:50:57:805 [BaseDriver]     "appium:mjpegServerPort": 12345,
2021-03-22 21:50:57:805 [BaseDriver]     "appium:mjpegScreenshotUrl": "http://m4:7810",
2021-03-22 21:50:57:805 [BaseDriver]     "appium:newCommandTimeout": 600,
2021-03-22 21:50:57:805 [BaseDriver]     "appium:noReset": true
2021-03-22 21:50:57:805 [BaseDriver]   },
2021-03-22 21:50:57:805 [BaseDriver]   "firstMatch": [
2021-03-22 21:50:57:806 [BaseDriver]     {}
2021-03-22 21:50:57:806 [BaseDriver]   ]
2021-03-22 21:50:57:806 [BaseDriver] }
2021-03-22 21:50:57:815 [BaseDriver] Session created with session id: c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a
2021-03-22 21:50:57:815 [UiAutomator2] Neither 'app' nor 'appPackage' was set. Starting UiAutomator2 without the target application
2021-03-22 21:50:57:816 [ADB] Using 'adb' from '/home/k/software/android-sdk/platform-tools/adb'
2021-03-22 21:50:57:816 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 start-server'
2021-03-22 21:50:57:824 [AndroidDriver] Retrieving device list
2021-03-22 21:50:57:824 [ADB] Trying to find a connected android device
2021-03-22 21:50:57:824 [ADB] Getting connected devices
2021-03-22 21:50:57:833 [ADB] Connected devices: [{"udid":"m4:5555","state":"device"},{"udid":"n2:5555","state":"device"},{"udid":"r2:5555","state":"device"},{"udid":"r3:5555","state":"device"},{"udid":"r5:5555","state":"device"}]
2021-03-22 21:50:57:834 [AndroidDriver] Using device: m4:5555
2021-03-22 21:50:57:834 [ADB] Using 'adb' from '/home/k/software/android-sdk/platform-tools/adb'
2021-03-22 21:50:57:834 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 start-server'
2021-03-22 21:50:57:843 [ADB] Setting device id to m4:5555
2021-03-22 21:50:57:843 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell getprop ro.build.version.sdk'
2021-03-22 21:50:58:029 [ADB] Current device property 'ro.build.version.sdk': 23
2021-03-22 21:50:58:030 [ADB] Device API level: 23
2021-03-22 21:50:58:031 [AndroidDriver] No app sent in, not parsing package/activity
2021-03-22 21:50:58:031 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 wait-for-device'
2021-03-22 21:50:58:040 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell echo ping'
2021-03-22 21:50:58:103 [AndroidDriver] Pushing settings apk to device...
2021-03-22 21:50:58:104 [ADB] Getting install status for io.appium.settings
2021-03-22 21:50:58:104 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.settings'
2021-03-22 21:50:58:200 [ADB] 'io.appium.settings' is installed
2021-03-22 21:50:58:200 [ADB] Getting package info for 'io.appium.settings'
2021-03-22 21:50:58:201 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.settings'
2021-03-22 21:50:58:291 [ADB] The version name of the installed 'io.appium.settings' is greater or equal to the application version name ('3.2.1' >= '3.2.1')
2021-03-22 21:50:58:291 [ADB] There is no need to install/upgrade '/home/k/.npm-global/lib/node_modules/appium/node_modules/io.appium.settings/apks/settings_apk-debug.apk'
2021-03-22 21:50:58:291 [ADB] Getting IDs of all 'io.appium.settings' processes
2021-03-22 21:50:58:292 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4\:5555 shell 'pgrep --help; echo $?''
2021-03-22 21:50:58:343 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell pgrep -f \(\[\[:blank:\]\]\|\^\)io\.appium\.settings\(\[\[:blank:\]\]\|\$\)'
2021-03-22 21:50:58:481 [AndroidDriver] io.appium.settings is already running. There is no need to reset its permissions.
2021-03-22 21:50:58:481 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell appops set io.appium.settings android:mock_location allow'
2021-03-22 21:50:59:791 [Logcat] Starting logs capture with command: /home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4\:5555 logcat -v threadtime
2021-03-22 21:50:59:844 [UiAutomator2] Forwarding UiAutomator2 Server port 6790 to local port 8205
2021-03-22 21:50:59:844 [ADB] Forwarding system: 8205 to device: 6790
2021-03-22 21:50:59:845 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward tcp:8205 tcp:6790'
2021-03-22 21:50:59:855 [ADB] Forwarding system: 12345 to device: 7810
2021-03-22 21:50:59:855 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward tcp:12345 tcp:7810'
2021-03-22 21:50:59:865 [ADB] Getting install status for io.appium.uiautomator2.server
2021-03-22 21:50:59:866 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server'
2021-03-22 21:50:59:928 [ADB] 'io.appium.uiautomator2.server' is installed
2021-03-22 21:50:59:928 [ADB] Getting package info for 'io.appium.uiautomator2.server'
2021-03-22 21:50:59:928 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server'
2021-03-22 21:50:59:988 [ADB] The version name of the installed 'io.appium.uiautomator2.server' is greater or equal to the application version name ('4.17.4' >= '4.17.4')
2021-03-22 21:50:59:989 [UiAutomator2] io.appium.uiautomator2.server installation state: sameVersionInstalled
2021-03-22 21:50:59:989 [ADB] Checking app cert for /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk
2021-03-22 21:50:59:992 [ADB] Using 'apksigner.jar' from '/home/k/software/android-sdk/apksigner.jar'
2021-03-22 21:50:59:993 [ADB] Starting apksigner: /lib/jvm/java-11-openjdk/bin/java -Xmx1024M -Xss1m -jar /home/k/software/android-sdk/apksigner.jar verify --print-certs /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk
2021-03-22 21:51:00:255 [ADB] apksigner stdout: Signer #1 certificate DN: EMAILADDRESS=android@android.com, CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
2021-03-22 21:51:00:255 [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
2021-03-22 21:51:00:255 [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
2021-03-22 21:51:00:256 [ADB]
2021-03-22 21:51:00:256 [ADB] sha256 hash did match for 'appium-uiautomator2-server-v4.17.4.apk'
2021-03-22 21:51:00:256 [ADB] '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk' is signed with the default certificate
2021-03-22 21:51:00:256 [ADB] Getting install status for io.appium.uiautomator2.server.test
2021-03-22 21:51:00:256 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys package io.appium.uiautomator2.server.test'
2021-03-22 21:51:00:391 [ADB] 'io.appium.uiautomator2.server.test' is installed
2021-03-22 21:51:00:392 [ADB] Checking app cert for /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk
2021-03-22 21:51:00:393 [ADB] Starting apksigner: /lib/jvm/java-11-openjdk/bin/java -Xmx1024M -Xss1m -jar /home/k/software/android-sdk/apksigner.jar verify --print-certs /home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk
2021-03-22 21:51:00:602 [ADB] apksigner stdout: Signer #1 certificate DN: EMAILADDRESS=android@android.com, CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
2021-03-22 21:51:00:602 [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
2021-03-22 21:51:00:602 [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
2021-03-22 21:51:00:602 [ADB]
2021-03-22 21:51:00:602 [ADB] sha256 hash did match for 'appium-uiautomator2-server-debug-androidTest.apk'
2021-03-22 21:51:00:603 [ADB] '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk' is signed with the default certificate
2021-03-22 21:51:00:603 [UiAutomator2] Server packages are not going to be (re)installed
2021-03-22 21:51:00:603 [UiAutomator2] Waiting up to 30000ms for services to be available
2021-03-22 21:51:00:604 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell pm list instrumentation'
2021-03-22 21:51:01:549 [UiAutomator2] Instrumentation target 'io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner' is available
2021-03-22 21:51:01:550 [ADB] Adding packages ["io.appium.settings","io.appium.uiautomator2.server","io.appium.uiautomator2.server.test"] to Doze whitelist
2021-03-22 21:51:01:550 [ADB] Got the following command chunks to execute: [["dumpsys","deviceidle","whitelist","+io.appium.settings",";","dumpsys","deviceidle","whitelist","+io.appium.uiautomator2.server",";","dumpsys","deviceidle","whitelist","+io.appium.uiautomator2.server.test",";"]]
2021-03-22 21:51:01:550 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys deviceidle whitelist +io.appium.settings ; dumpsys deviceidle whitelist +io.appium.uiautomator2.server ; dumpsys deviceidle whitelist +io.appium.uiautomator2.server.test ;'
2021-03-22 21:51:01:666 [UiAutomator2] No app capability. Assuming it is already on the device
2021-03-22 21:51:01:667 [UiAutomator2] Performing shallow cleanup of automation leftovers
2021-03-22 21:51:01:673 [UiAutomator2] No obsolete sessions have been detected (socket hang up)
2021-03-22 21:51:01:673 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell am force-stop io.appium.uiautomator2.server.test'
2021-03-22 21:51:02:669 [UiAutomator2] Starting UIAutomator2 server 4.17.4
2021-03-22 21:51:02:670 [UiAutomator2] Using UIAutomator2 server from '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-v4.17.4.apk' and test from '/home/k/.npm-global/lib/node_modules/appium/node_modules/appium-uiautomator2-server/apks/appium-uiautomator2-server-debug-androidTest.apk'
2021-03-22 21:51:02:670 [UiAutomator2] Waiting up to 30000ms for UiAutomator2 to be online...
2021-03-22 21:51:02:670 [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","m4:5555","shell","am","instrument","-w","io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner"]
2021-03-22 21:51:02:681 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:51:02:682 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:51:02:690 [WD Proxy] socket hang up
2021-03-22 21:51:03:690 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:51:03:691 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:51:03:697 [WD Proxy] socket hang up
2021-03-22 21:51:04:291 [Instrumentation] io.appium.uiautomator2.server.test.AppiumUiAutomator2Server:
2021-03-22 21:51:04:698 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:51:04:699 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:51:04:719 [WD Proxy] socket hang up
2021-03-22 21:51:05:720 [WD Proxy] Matched '/status' to command name 'getStatus'
2021-03-22 21:51:05:720 [WD Proxy] Proxying [GET /status] to [GET http://127.0.0.1:8205/wd/hub/status] with no body
2021-03-22 21:51:05:932 [WD Proxy] Got response with status 200: {"sessionId":"None","value":{"message":"UiAutomator2 Server is ready to accept commands","ready":true}}
2021-03-22 21:51:05:932 [UiAutomator2] The initialization of the instrumentation process took 3262ms
2021-03-22 21:51:05:933 [WD Proxy] Matched '/session' to command name 'createSession'
2021-03-22 21:51:05:933 [WD Proxy] Proxying [POST /session] to [POST http://127.0.0.1:8205/wd/hub/session] with body: {"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555"}],"alwaysMatch":{}}}
2021-03-22 21:51:05:972 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":{"capabilities":{"firstMatch":[{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555"}],"alwaysMatch":{}},"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128"}}
2021-03-22 21:51:05:972 [WD Proxy] Determined the downstream protocol as 'W3C'
2021-03-22 21:51:05:992 [WD Proxy] Proxying [GET /appium/device/info] to [GET http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128/appium/device/info] with no body
2021-03-22 21:51:06:046 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":{"androidId":"4cea0ae73854c9e9","apiVersion":"23","bluetooth":{"state":"OFF"},"brand":"Xiaomi","carrierName":"","displayDensity":480,"locale":"zh_CN","manufacturer":"Xiaomi","model":"MI 4LTE","networks":[{"capabilities":{"SSID":null,"linkDownBandwidthKbps":1048576,"linkUpstreamBandwidthKbps":1048576,"networkCapabilities":"NET_CAPABILITY_NOT_RESTRICTED,NET_CAPABILITY_NOT_VPN,NET_CAPABILITY_INTERNET,NET_CAPABILITY_TRUSTED,NET_CAPABILITY_VALIDATED","signalStrength":-54,"transportTypes":"TRANSPORT_WIFI"},"detailedState":"CONNECTED","extraInfo":"\"Blue5_5G\"","isAvailable":true,"isConnected":true,"isFailover":false,"isRoaming":false,"state":"CONNECTED","subtype":0,"subtypeName":"","type":1,"typeName":"WIFI"}],"platformVersion":"6.0.1","realDisplaySize":"1080x1920","timeZone":"Asia/Shanghai"}}
2021-03-22 21:51:06:047 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 shell dumpsys window'
2021-03-22 21:51:06:147 [AndroidDriver] Screen already unlocked, doing nothing
2021-03-22 21:51:06:168 [WD Proxy] Proxying [GET /appium/device/pixel_ratio] to [GET http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128/appium/device/pixel_ratio] with no body
2021-03-22 21:51:06:191 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":3}
2021-03-22 21:51:06:193 [WD Proxy] Matched '/appium/device/system_bars' to command name 'getSystemBars'
2021-03-22 21:51:06:193 [WD Proxy] Proxying [GET /appium/device/system_bars] to [GET http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128/appium/device/system_bars] with no body
2021-03-22 21:51:06:258 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":{"statusBar":60}}
2021-03-22 21:51:06:258 [WD Proxy] Matched '/window/current/size' to command name 'getWindowSize'
2021-03-22 21:51:06:259 [WD Proxy] Proxying [GET /window/current/size] to [GET http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128/window/current/size] with no body
2021-03-22 21:51:06:268 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":{"height":1920,"width":1080}}

2021-03-22 21:51:06:268 [UiAutomator2] Starting MJPEG stream reading URL: 'http://m4:7810'
2021-03-22 21:51:06:625 [Appium] New AndroidUiautomator2Driver session created successfully, session c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a added to master session list
2021-03-22 21:51:06:626 [BaseDriver] Event 'newSessionStarted' logged at 1616421066626 (21:51:06 GMT+0800 (China Standard Time))
2021-03-22 21:51:06:626 [W3C (c20bc8b8)] Cached the protocol value 'W3C' for the new session c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a
2021-03-22 21:51:06:627 [W3C (c20bc8b8)] Responding to client with driver.createSession() result: {"capabilities":{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true},"platformName":"Android","automationName":"uiautomator2","udid":"m4:5555","mjpegServerPort":12345,"mjpegScreenshotUrl":"http://m4:7810","newCommandTimeout":600,"noReset":true,"deviceName":"m4:5555","deviceUDID":"m4:5555","deviceApiLevel":23,"platformVersion":"6.0.1","deviceScreenSize":"1080x1920","deviceScreenDensity":480,"deviceModel":"MI 4LTE","deviceManufacturer":"Xiaomi","pixelRatio":3,"statBarHeight":60,"viewportRect":{"left":0,"top":60,"width":1080,"height":1860}}}
2021-03-22 21:51:06:629 [HTTP] <-- POST /wd/hub/session 200 8826 ms - 934
2021-03-22 21:51:06:629 [HTTP]


2021-03-22 21:51:11:221 [HTTP] --> GET /wd/hub/session/c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a/appium/settings
2021-03-22 21:51:11:221 [HTTP] {}
2021-03-22 21:51:11:221 [W3C (c20bc8b8)] Calling AppiumDriver.getSettings() with args: ["c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a"]
2021-03-22 21:51:11:222 [WD Proxy] Matched '/appium/settings' to command name 'getSettings'
2021-03-22 21:51:11:223 [WD Proxy] Proxying [GET /appium/settings] to [GET http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128/appium/settings] with no body
2021-03-22 21:51:11:246 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":{"keyInjectionDelay":0,"mjpegScalingFactor":50,"trackScrollEvents":true,"normalizeTagNames":false,"useResourcesForOrientationDetection":false,"mjpegServerScreenshotQuality":50,"wakeLockTimeout":86394189,"waitForSelectorTimeout":10000,"mjpegServerPort":12345,"ignoreUnimportantViews":false,"simpleBoundsCalculation":false,"shutdownOnPowerDisconnect":true,"scrollAcknowledgmentTimeout":200,"mjpegServerFramerate":10,"elementResponseAttributes":"","enableMultiWindows":false,"actionAcknowledgmentTimeout":3000,"serverPort":6790,"waitForIdleTimeout":10000,"allowInvisibleElements":false,"enableNotificationListener":true,"mjpegBilinearFiltering":false,"shouldUseCompactResponses":true}}
2021-03-22 21:51:11:246 [W3C (c20bc8b8)] Responding to client with driver.getSettings() result: {"imageMatchThreshold":0.4,"fixImageFindScreenshotDims":true,"fixImageTemplateSize":false,"fixImageTemplateScale":false,"defaultImageTemplateScale":1,"checkForImageElementStaleness":true,"autoUpdateImageElementPosition":false,"imageElementTapStrategy":"w3cActions","getMatchedImageResult":false,"ignoreUnimportantViews":false,"allowInvisibleElements":false,"keyInjectionDelay":0,"mjpegScalingFactor":50,"trackScrollEvents":true,"normalizeTagNames":false,"useResourcesForOrientationDetection":false,"mjpegServerScreenshotQuality":50,"wakeLockTimeout":86394189,"waitForSelectorTimeout":10000,"mjpegServerPort":12345,"simpleBoundsCalculation":false,"shutdownOnPowerDisconnect":true,"scrollAcknowledgmentTimeout":200,"mjpegServerFramerate":10,"elementResponseAttributes":"","enableMultiWindows":false,"actionAcknowledgmentTimeout":3000,"serverPort":6790,"waitForIdleTimeout":10000,"enableNotificationListener":true,"mjpegBilinearFiltering":false,"shouldUseCompactResponses":true}
2021-03-22 21:51:11:247 [HTTP] <-- GET /wd/hub/session/c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a/appium/settings 200 26 ms - 985
2021-03-22 21:51:11:247 [HTTP]


2021-03-22 21:51:14:714 [HTTP] --> DELETE /wd/hub/session/c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a
2021-03-22 21:51:14:715 [HTTP] {}
2021-03-22 21:51:14:715 [W3C (c20bc8b8)] Calling AppiumDriver.deleteSession() with args: ["c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a"]
2021-03-22 21:51:14:715 [BaseDriver] Event 'quitSessionRequested' logged at 1616421074715 (21:51:14 GMT+0800 (China Standard Time))
2021-03-22 21:51:14:716 [Appium] Removing session c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a from our master session list
2021-03-22 21:51:14:717 [UiAutomator2] Deleting UiAutomator2 session
2021-03-22 21:51:14:717 [UiAutomator2] Deleting UiAutomator2 server session
2021-03-22 21:51:14:718 [WD Proxy] Matched '/' to command name 'deleteSession'
2021-03-22 21:51:14:718 [WD Proxy] Proxying [DELETE /] to [DELETE http://127.0.0.1:8205/wd/hub/session/25d5c90d-fb9f-420e-aa3f-03231ce11128] with no body
2021-03-22 21:51:14:744 [WD Proxy] Got response with status 200: {"sessionId":"25d5c90d-fb9f-420e-aa3f-03231ce11128","value":null}
2021-03-22 21:51:14:744 [Logcat] Stopping logcat capture
2021-03-22 21:51:14:746 [ADB] Removing forwarded port socket connection: 8205
2021-03-22 21:51:14:746 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:8205'
2021-03-22 21:51:14:756 [ADB] Removing forwarded port socket connection: 12345
2021-03-22 21:51:14:757 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:12345'
2021-03-22 21:51:14:768 [UiAutomator2] Closing MJPEG stream
2021-03-22 21:51:14:769 [BaseDriver] Event 'quitSessionFinished' logged at 1616421074769 (21:51:14 GMT+0800 (China Standard Time))
2021-03-22 21:51:14:770 [W3C (c20bc8b8)] Received response: null
2021-03-22 21:51:14:770 [W3C (c20bc8b8)] But deleting session, so not returning
2021-03-22 21:51:14:770 [W3C (c20bc8b8)] Responding to client with driver.deleteSession() result: null
2021-03-22 21:51:14:772 [HTTP] <-- DELETE /wd/hub/session/c20bc8b8-a9d4-427f-a15f-b3fbc2cd358a 200 57 ms - 14
2021-03-22 21:51:14:772 [HTTP]
2021-03-22 21:51:15:451 [Instrumentation] .
2021-03-22 21:51:16:742 [Instrumentation] Time: 11.168
2021-03-22 21:51:16:743 [Instrumentation]
2021-03-22 21:51:16:743 [Instrumentation] OK (1 test)
2021-03-22 21:51:16:970 [Instrumentation] The process has exited with code 0

2021-03-22 21:57:48:229 [BaseDriver] Shutting down because we waited 600 seconds for a command
2021-03-22 21:57:48:230 [Appium] Closing session, cause was 'New Command Timeout of 600 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability'
2021-03-22 21:57:48:230 [Appium] Removing session 'ce20dea4-d2b1-4bac-9995-e1d016e6a09e' from our master session list
2021-03-22 21:57:48:230 [UiAutomator2] Deleting UiAutomator2 session
2021-03-22 21:57:48:231 [ADB] Removing forwarded port socket connection: 8205
2021-03-22 21:57:48:231 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:8205'
2021-03-22 21:57:48:243 [ADB] Removing forwarded port socket connection: 12345
2021-03-22 21:57:48:244 [ADB] Running '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4:5555 forward --remove tcp:12345'
2021-03-22 21:57:48:268 [UiAutomator2] Unable to remove MJPEG server port forward: Error executing adbExec. Original error: 'Command '/home/k/software/android-sdk/platform-tools/adb -P 5037 -s m4\:5555 forward --remove tcp\:12345' exited with code 1'; Stderr: 'adb: error: listener 'tcp:12345' not found'; Code: '1'
2021-03-22 21:57:48:268 [UiAutomator2] Closing MJPEG stream