干貨|app自動化測試之Appium問題分析及定位
使用 Appium 進(jìn)行測試時，會產(chǎn)生大量日志，一旦運(yùn)行過程中遇到報(bào)錯，可以通過 Appium 服務(wù)端的日志以及客戶端的日志分析排查問題。
Appium Server日志-開啟服務(wù)
通過命令行的方式啟動 Appium Server，下面來分析一下啟動日志，日志第一行顯示了 Appium 版本信息和服務(wù)在本地的運(yùn)行地址。
$ appium -g appium.log
[Appium] Welcome to Appium v1.8.0-beta3 (REV \
?40e40975ebd3593d08c3f83de2546258f7ddf11d)
[Appium] Appium REST http interface listener started \
?on 0.0.0.0:4723
如果啟動 Appium 服務(wù)時添加了參數(shù)，會在啟動日志中展示，比如添加了 defaultCapabilities，啟動日志也會顯示出來。
Hogwarts $ appium --log-timestamp --log-no-colors --no-reset ? ?
2021-04-29 10:11:58:545 - [Appium] Welcome to Appium v1.17.0
2021-04-29 10:11:58:547 - [Appium] Non-default server args:
2021-04-29 10:11:58:547 - [Appium] ? logTimestamp: true
2021-04-29 10:11:58:547 - [Appium] ? logNoColors: true
2021-04-29 10:11:58:547 - [Appium] ? noReset: true
2021-04-29 10:11:58:548 - [Appium] Deprecated server args:
2021-04-29 10:11:58:548 - [Appium] ? --no-reset => --default-capabilities '{"noReset":true}'
2021-04-29 10:11:58:548 - [Appium] Default capabilities, which will be added to each request unless overridden by desired capabilities:
2021-04-29 10:11:58:548 - [Appium] ? noReset: true
2021-04-29 10:11:58:567 - [Appium] Appium REST http interface listener started on 0.0.0.0:4723
Appium 參數(shù)：CLI Arguments - Appium 1
defaultCapabilities 詳見：The --default-capabilities flag - Appium 1
運(yùn)行時的Session日志
自動化測試運(yùn)行起來之后，Appium Server 的日志提供了一些基本的 Session 信息，特別是 desired capabilities 的配置信息。應(yīng)該時刻注意 Appium 服務(wù)是否正確接收了請求內(nèi)容。
...
[debug] [BaseDriver] Creating session with W3C capabilities: {
[debug] [BaseDriver] ? "alwaysMatch": {
[debug] [BaseDriver] ? ? "platformName": "android",
[debug] [BaseDriver] ? ? "appium:appActivity": ".view.WelcomeActivityAlias",
[debug] [BaseDriver] ? ? "appium:appPackage": "com.xueqiu.android",
[debug] [BaseDriver] ? ? "appium:automationName": "UiAutomator2",
[debug] [BaseDriver] ? ? "appium:deviceName": "emulator-5554",
[debug] [BaseDriver] ? ? "appium:noReset": "true",
[debug] [BaseDriver] ? ? "appium:udid": "emulator-5554"
[debug] [BaseDriver] ? },
...
上面的日志創(chuàng)建了一個 Session，設(shè)置了 Capabilities 參數(shù)，以 JSON 格式告訴 AppiumServer 被測試設(shè)備的一些重要信息。
Appium GET 請求的日志
Appium 是一個 REST 服務(wù)，接收 HTTP 請求，返回結(jié)果。Appium 服務(wù)端日志用 [HTTP] → 和 [HTTP] <–展示了請求和返回的信息。
[HTTP] --> GET /wd/hub/status {}
[debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
[debug] [MJSONWP] Responding to client with driver.getStatus()\
result: {"build":{"version":"1.8.0-beta3","revision":"30e7b45bdc5668124af33c41492aa5195fcdf64d"}}
[HTTP] <-- GET /wd/hub/status 200 121 ms - 126
“–>”代表發(fā)出 HTTP 請求，“<–”代表響應(yīng)，中間是指令細(xì)節(jié)。[MJSONWP] 指使用 MJSONWP(Mobile JSON Wire Protocol 協(xié)議)，調(diào)用 AppiumDriver.getStatus( )這個方法（無參），返回給客戶端 result 信息，整個過程耗時 121 毫秒，傳輸了 126 個字節(jié)。
通過日志進(jìn)行錯誤排查
利用日志可以非常容易的排查和定位問題，問題通常發(fā)生在 automation Session 之后，如果 Session 持續(xù)存在，錯誤也可能發(fā)生。
[HTTP] --> POST /wd/hub/session?
...?
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/user/Android/Sdk/platform-tools//adb' \
with args: ["-P",5037,"-s","ec8c4df","shell","am","force-stop",\
"io.appium.unlock"]
?[debug] [AndroidDriver] Not cleaning generated files. Add \
`clearSystemFiles` capability if wanted.?
[MJSONWP] Encountered internal error running command: Error: \?
Cannot stop and clear com.company.app. Original error: Error \
?executing adbExec. Original error: 'Command '/home/user/Android\
/Sdk/platform-tools//adb -P 5037 -s ec8c4df shell pm clear com.\
company.app' exited with code 1'; Stderr: 'Error: java.lang.SecurityException:\?
PID 22126 does not have permission android.permission.CLEAR_APP_USER_DATA to?
\clear data of package com.company.app'; Code: '1'
at Object.wrappedLogger.errorAndThrow (../../lib/logging.js:63:13)
at ADB.callee$0$0$ (../../../lib/tools/adb-commands.js:334:9)
at tryCatch (/home/linuxbrew/.linuxbrew/lib/node_modules/appium/node_modules\
/babel-runtime/regenerator/runtime.js:67:40)
at GeneratorFunctionPrototype.invoke [as _invoke] (/home/linuxbrew/.\
linuxbrew/lib/node_modules/appium/node_modules/babel-runtime/regenerator\
/runtime.js:315:22)
....
[HTTP] <-- POST /wd/hub/session 500 40811 ms - 557
Appium Driver 啟動 Session ，清理 com.company.app 時發(fā)生錯誤。這個錯誤讓我們知道兩件事：“Appium 正在嘗試做什么”，“哪里出錯了”。
在這個例子中，Appium 嘗試運(yùn)行 adb 命令（adb shell am force-stop），adb 參數(shù)在錯誤信息中也有顯示。發(fā)生了 Android 系統(tǒng)權(quán)限錯誤。此時，可以手動運(yùn)行這個 adb 命令，查看錯誤是否可以重現(xiàn)。如果錯誤重現(xiàn)，可以通過錯誤類型定位問題。
這個例子只是眾多錯誤中的一個，但它說明至關(guān)重要的一點(diǎn)，當(dāng)錯誤發(fā)生時，日志可以提供更多的信息，如果沒有完整的日志信息，對 Appium 排錯難上加難。
改變?nèi)罩据敵龅膮?shù)
下面的參數(shù)可以改變 Appium 服務(wù)端的日志行為：
–log-level：改變 Appium 日志顯示級別。Appium 默認(rèn)展示所有日志
，它有以下一些選項(xiàng)：‘info’, ‘info:debug’, ‘info:info’, ‘info:warn’, ‘info:error’, …
–log-no-colors：關(guān)閉顏色，如果日志是彩色的，可能會出現(xiàn)奇怪的字符，比如"TODO: find the color"，你可以用這個參數(shù)關(guān)閉顏色。
–log-timestamp：在日志前添加時間戳
展示如下：
2018-03-15 13:17:58:663 - [Appium] Welcome to Appium v1.8.0-beta3 (REV 30e7b45bdc5668124af33c41492aa5195fcdf64d)
2018-03-15 13:17:58:664 - [Appium] Non-default server args:
2018-03-15 13:17:58:665 - [Appium] logTimestamp: true
2018-03-15 13:17:58:732 - [Appium] Appium REST http interface listener started on 0.0.0.0:4723
