appium日志分析详解

Microsoft Windows [版本 10.0.18363.1016]
(c) 2019 Microsoft Corporation。保留所有权利。

C:\Users\lnz>appium
[Appium] Welcome to Appium v1.15.1
#端口开启
[Appium] Appium REST http interface listener started on 0.0.0.0:4723
#接收到创建会话的请求
[HTTP] --> POST /wd/hub/session
#请求体数据
[HTTP] {"capabilities":{"firstMatch":[{"platformName":"Android","appium:deviceName":"Android Emulator","appium:appPackage":"com.xueqiu.android","appium:appActivity":".view.WelcomeActivityAlias","appium:autoGrantPermissions":"true","appium:noReset":"true","appium:newCommandTimeout":"180","appium:udid":null,"appium:systemPort":42380,"appium:mjpegServerPort":42381}]},"desiredCapabilities":{"platformName":"Android","deviceName":"Android Emulator","appPackage":"com.xueqiu.android","appActivity":".view.WelcomeActivityAlias","autoGrantPermissions":"true","noReset":"true","newCommandTimeout":"180","udid":null,"systemPort":42380,"mjpegServerPort":42381}}
#调用AppiumDrive创建session
[debug] [W3C] Calling AppiumDriver.createSession() with args: [{"platformName":"Android","deviceName":"Android Emulator","appPackage":"com.xueqiu.android","appActivity":".view.WelcomeActivityAlias","autoGrantPermissions":"true","noReset":"true","newCommandTimeout":"180","udid":null,"systemPort":42380,"mjpegServerPort":42381},null,{"firstMatch":[{"platformName":"Android","appium:deviceName":"Android Emulator","appium:appPackage":"com.xueqiu.android","appium:appActivity":".view.WelcomeActivityAlias","appium:autoGrantPermissions":"true","appium:noReset":"true","appium:newCommandTimeout":"180","appium:udid":null,"appium:systemPort":42380,"appium:mjpegServerPort":42381}]}]
[debug] [BaseDriver] Event 'newSessionRequested' logged at 1599533600101 (10:53:20 GMT+0800 (GMT+08:00))
[BaseDriver] Number capability passed in as string. Functionality may be compromised.
[Appium]
[Appium] ======================================================================
[Appium]   DEPRECATION WARNING:
[Appium]
[Appium]   The 'automationName' capability was not provided in the desired
[Appium]   capabilities for this Android session
[Appium]
[Appium]   Setting 'automationName=UiAutomator2' by default and using the
[Appium]   UiAutomator2 Driver
[Appium]
[Appium]   The next major version of Appium (2.x) will **require** the
[Appium]   'automationName' capability to be set for all sessions on all
[Appium]   platforms
[Appium]
[Appium]   In previous versions (Appium <= 1.13.x), the default was
[Appium]   'automationName=UiAutomator1'
[Appium]
[Appium]   If you wish to use that automation instead of UiAutomator2, please
[Appium]   add 'automationName=UiAutomator1' to your desired capabilities
[Appium]
[Appium]   For more information about drivers, please visit
[Appium]   http://appium.io/docs/en/about-appium/intro/ and explore the
[Appium]   'Drivers' menu
[Appium]
[Appium] ======================================================================
[Appium]
#创建新的AndroidUiautomator2Driver（v1.37.2）会话
[Appium] Appium v1.15.1 creating new AndroidUiautomator2Driver (v1.37.2) session
#提供了W3C功能和MJSONWP所需的功能
[debug] [BaseDriver] W3C capabilities and MJSONWP desired capabilities were provided
#使用capabilities数据创建会话
[debug] [BaseDriver] Creating session with W3C capabilities: {
[debug] [BaseDriver]   "alwaysMatch": {
[debug] [BaseDriver]     "platformName": "Android",
[debug] [BaseDriver]     "appium:deviceName": "Android Emulator",
[debug] [BaseDriver]     "appium:appPackage": "com.xueqiu.android",
[debug] [BaseDriver]     "appium:appActivity": ".view.WelcomeActivityAlias",
[debug] [BaseDriver]     "appium:autoGrantPermissions": "true",
[debug] [BaseDriver]     "appium:noReset": "true",
[debug] [BaseDriver]     "appium:newCommandTimeout": "180",
[debug] [BaseDriver]     "appium:udid": null,
[debug] [BaseDriver]     "appium:systemPort": 42380,
[debug] [BaseDriver]     "appium:mjpegServerPort": 42381
[debug] [BaseDriver]   },
[debug] [BaseDriver]   "firstMatch": [
[debug] [BaseDriver]     {}
[debug] [BaseDriver]   ]
[debug] [BaseDriver] }
[BaseDriver] Number capability passed in as string. Functionality may be compromised.
[BaseDriver] Capability 'noReset' changed from string to boolean. This may cause unexpected behavior
[BaseDriver] Capability 'autoGrantPermissions' changed from string to boolean. This may cause unexpected behavior
[BaseDriver] Capability 'newCommandTimeout' changed from string ('180') to integer (180). This may cause unexpected behavior
[BaseDriver] The following capabilities were provided, but are not recognized by Appium:
[BaseDriver]   mjpegServerPort
#创建成功会话id:02fcf169-ae94-49ed-93ed-909781f1a452
[BaseDriver] Session created with session id: 02fcf169-ae94-49ed-93ed-909781f1a452
#开启雪球app
[UiAutomator2] Starting 'com.xueqiu.android' directly on the device
#找到3个 'build-tools' folders  在'D:\Program Files (x86)\appium\sdk'下
[ADB] Found 3 'build-tools' folders under 'D:\Program Files (x86)\appium\sdk' (newest first):
[ADB]     D:/Program Files (x86)/appium/sdk/build-tools/29.0.3
[ADB]     D:/Program Files (x86)/appium/sdk/build-tools/29.0.2
[ADB]     D:/Program Files (x86)/appium/sdk/build-tools/28.0.3
#使用adb
[ADB] Using 'adb.exe' from 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe'
#获取设备列表
[AndroidDriver] Retrieving device list
#尝试找到一个连接的安卓设备
[debug] [ADB] Trying to find a connected android device
#正在连接设备
[debug] [ADB] Getting connected devices...
#连接到的设备列表
[debug] [ADB] Connected devices: [{"udid":"127.0.0.1:7555","state":"device"}]
#使用设备 127.0.0.1:7555
[AndroidDriver] Using device: 127.0.0.1:7555
#使用adb
[ADB] Using 'adb.exe' from 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe'
#设置设备id
[debug] [ADB] Setting device id to 127.0.0.1:7555
#获取adb命令获取sdk版本信息
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell getprop ro.build.version.sdk'
#获取到了版本信息：23
[debug] [ADB] Current device property 'ro.build.version.sdk': 23
[debug] [ADB] Device API level: 23
[AndroidDriver] No app sent in, not parsing package/activity
#等待设备
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 wait-for-device'
#ping
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell echo ping'
#推送io.appium.settings  apk文件到设备
[debug] [AndroidDriver] Pushing settings apk to device...
#获取io.appium.settings 的安装状态
[debug] [ADB] Getting install status for io.appium.settings
#运行adb命令 检查io.appium.settings 的安装状态
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell dumpsys package io.appium.settings'
#运行结果是未安装
[debug] [ADB] 'io.appium.settings' is not installed
[debug] [ADB] App 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\io.appium.settings\apks\settings_apk-debug.apk' is not installed

[debug] [ADB] Installing 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\io.appium.settings\apks\settings_apk-debug.apk'

[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell 'ls -t -1 /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
[debug] [ADB] The current Android API does not support extended ls options. Defaulting to no-options call
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell 'ls /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
[debug] [ADB] The count of applications in the cache: 4
[ADB] The application at 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\io.appium.settings\apks\settings_apk-debug.apk' is already cached to '/data/local/tmp/appium_cache/3d97225b036c28750562ef8962defee6b1af19a4.apk'
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pm install -g /data/local/tmp/appium_cache/3d97225b036c28750562ef8962defee6b1af19a4.apk'
[ADB] The installation of 'settings_apk-debug.apk' took 0.504s
[debug] [ADB] Install command stdout: pkg: /data/local/tmp/appium_cache/3d97225b036c28750562ef8962defee6b1af19a4.apk
[debug] [ADB] Success
[debug] [ADB] Getting IDs of all 'io.appium.settings' processes
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell 'pgrep --help; echo $?''
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pgrep -f io\\.appium\\.settings'
[AndroidDriver] Granting android.permission.SET_ANIMATION_SCALE, CHANGE_CONFIGURATION, ACCESS_FINE_LOCATION by pm grant
#为'io.appium.settings' 授权
[debug] [ADB] Granting permissions ["android.permission.SET_ANIMATION_SCALE","android.permission.CHANGE_CONFIGURATION","android.permission.ACCESS_FINE_LOCATION"] to 'io.appium.settings'
[debug] [ADB] Got the following command chunks to execute: [["pm","grant","io.appium.settings","android.permission.SET_ANIMATION_SCALE",";","pm","grant","io.appium.settings","android.permission.CHANGE_CONFIGURATION",";","pm","grant","io.appium.settings","android.permission.ACCESS_FINE_LOCATION",";"]]
#授权
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pm grant io.appium.settings android.permission.SET_ANIMATION_SCALE \; pm grant io.appium.settings android.permission.CHANGE_CONFIGURATION \; pm grant io.appium.settings android.permission.ACCESS_FINE_LOCATION \;'
# 启动io.appium.settings ，指定启动.Settings  Activity ，指定 action 为android.intent.action.MAIN
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell am start -n io.appium.settings/.Settings -a android.intent.action.MAIN -c android.intent.category.LAUNCHER'
#获取进程id
[debug] [ADB] Getting IDs of all 'io.appium.settings' processes
#运行命令 获取io.appium.settings 的进行id
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pgrep -f io\\.appium\\.settings'
#设备模拟位置允许
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell appops set io.appium.settings android\:mock_location allow'
#开始捕获日志
[debug] [Logcat] Starting logcat capture
#获取io.appium.uiautomator2.server的安装状态
[debug] [ADB] Getting install status for io.appium.uiautomator2.server
#运行命令去获取
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell dumpsys package io.appium.uiautomator2.server'
#结果是未安装的
[debug] [ADB] 'io.appium.uiautomator2.server' is not installed
[debug] [ADB] App 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-v4.3.0.apk' is not installed
[debug] [UiAutomator2] io.appium.uiautomator2.server installation state: notInstalled
#检查app的签名
[debug] [ADB] Checking app cert for C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-v4.3.0.apk
[ADB] Using 'apksigner.bat' from 'D:\Program Files (x86)\appium\sdk\build-tools\29.0.3\apksigner.bat'
[debug] [ADB] Starting 'D:\Program Files (x86)\appium\sdk\build-tools\29.0.3\apksigner.bat' with args '["verify","--print-certs","C:\\Users\\lnz\\AppData\\Roaming\\npm\\node_modules\\appium\\node_modules\\appium-uiautomator2-server\\apks\\appium-uiautomator2-server-v4.3.0.apk"]'
[debug] [ADB] apksigner stdout: Signer #1 certificate DN: [email protected], CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
[debug] [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
[debug] [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
[debug] [ADB] Signer #1 certificate MD5 digest: e89b158e4bcf988ebd09eb83f5378e87
[debug] [ADB]
[debug] [ADB] 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-v4.3.0.apk' is already signed.
#获取io.appium.uiautomator2.server.test 的安装状态
[debug] [ADB] Getting install status for io.appium.uiautomator2.server.test
#运行adb命令
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell dumpsys package io.appium.uiautomator2.server.test'
[debug] [ADB] 'io.appium.uiautomator2.server.test' is not installed
#检查签名
[debug] [ADB] Checking app cert for C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-debug-androidTest.apk
[debug] [ADB] Starting 'D:\Program Files (x86)\appium\sdk\build-tools\29.0.3\apksigner.bat' with args '["verify","--print-certs","C:\\Users\\lnz\\AppData\\Roaming\\npm\\node_modules\\appium\\node_modules\\appium-uiautomator2-server\\apks\\appium-uiautomator2-server-debug-androidTest.apk"]'
[debug] [ADB] apksigner stdout: Signer #1 certificate DN: [email protected], CN=Android, OU=Android, O=Android, L=Mountain View, ST=California, C=US
[debug] [ADB] Signer #1 certificate SHA-256 digest: a40da80a59d170caa950cf15c18c454d47a39b26989d8b640ecd745ba71bf5dc
[debug] [ADB] Signer #1 certificate SHA-1 digest: 61ed377e85d386a8dfee6b864bd85b0bfaa5af81
[debug] [ADB] Signer #1 certificate MD5 digest: e89b158e4bcf988ebd09eb83f5378e87
[debug] [ADB]
[debug] [ADB] 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-debug-androidTest.apk' is already signed.
[UiAutomator2] Server packages are going to be (re)installed
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell 'ls /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
[debug] [ADB] The count of applications in the cache: 4
[ADB] The application at 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-v4.3.0.apk' is already cached to '/data/local/tmp/appium_cache/0cc1725a60a05dbb5d0d09256f2fc6ece7e3b10f.apk'
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pm install -r /data/local/tmp/appium_cache/0cc1725a60a05dbb5d0d09256f2fc6ece7e3b10f.apk'
[ADB] The installation of 'appium-uiautomator2-server-v4.3.0.apk' took 0.678s
[debug] [ADB] Install command stdout: pkg: /data/local/tmp/appium_cache/0cc1725a60a05dbb5d0d09256f2fc6ece7e3b10f.apk
[debug] [ADB] Success
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell 'ls /data/local/tmp/appium_cache 2>&1 || echo _ERROR_''
[debug] [ADB] The count of applications in the cache: 4
[ADB] The application at 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-debug-androidTest.apk' is already cached to '/data/local/tmp/appium_cache/cd247f042368990c9f33b2d7bf2390d8cf4f4e24.apk'
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pm install -r /data/local/tmp/appium_cache/cd247f042368990c9f33b2d7bf2390d8cf4f4e24.apk'
[ADB] The installation of 'appium-uiautomator2-server-debug-androidTest.apk' took 0.565s
[debug] [ADB] Install command stdout: pkg: /data/local/tmp/appium_cache/cd247f042368990c9f33b2d7bf2390d8cf4f4e24.apk
[debug] [ADB] Success
#等待UiAutomator2 server服务启动
[debug] [UiAutomator2] Waiting up to 30000ms for services to be available
#列出测试包
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell pm list instrumentation'
[debug] [UiAutomator2] Instrumentation target 'io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner' is available
[debug] [UiAutomator2] Forwarding UiAutomator2 Server port 6790 to 42380
#准备转发appium上的 端口42380  到设置上的端口6790
[debug] [ADB] Forwarding system: 42380  to device: 6790
#执行端口转发命令
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 forward tcp\:42380 tcp\:6790'
[debug] [UiAutomator2] No app capability. Assuming it is already on the device
#清理自动化留下的浅层数据
[debug] [UiAutomator2] Performing shallow cleanup of automation leftovers
#没有过期的会话
[debug] [UiAutomator2] No obsolete sessions have been detected (Error: socket hang up)
#强制停止io.appium.uiautomator2.server.test
[debug] [ADB] Running 'D:\Program Files (x86)\appium\sdk\platform-tools\adb.exe -P 5037 -s 127.0.0.1\:7555 shell am force-stop io.appium.uiautomator2.server.test'
#在模拟器/真机上开启 UIAutomator2 server
[UiAutomator2] Starting UIAutomator2 server 4.3.0
[UiAutomator2] Using UIAutomator2 server from 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-v4.3.0.apk' and test from 'C:\Users\lnz\AppData\Roaming\npm\node_modules\appium\node_modules\appium-uiautomator2-server\apks\appium-uiautomator2-server-debug-androidTest.apk'
#等待服务在线
[UiAutomator2] Waiting up to 30000ms for UiAutomator2 to be online...
#创建子进程 
[debug] [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","127.0.0.1:7555","shell","am","instrument","-w","io.appium.uiautomator2.server.test/androidx.test.runner.AndroidJUnitRunner"]
[debug] [Instrumentation] io.appium.uiautomator2.server.test.AppiumUiAutomator2Server:
#获取状态
[debug] [WD Proxy] Matched '/status' to command name 'getStatus'
[debug] [WD Proxy] Proxying [GET /status] to [GET http://localhost:42380/wd/h