Appium 常见问题分析与定位

Appium 问题分析定位

Appium 服务器运行时会产生很多日志，一旦运行过程中遇到报错，需要结合Appium服务端与客户端的日志分析来排查问题，有时也需要结合手机端应用的日志信息进行排查。

1. 服务日志

1.1 开启服务

打开命令行工具，执行appium回车，日志第一行显示了 Appium 版本和服务地址。

$ appium
[Appium] Welcome to Appium v1.8.0-beta3 (REV \
  40e40975ebd3593d08c3f83de2546258f7ddf11d)
[Appium] Appium REST http interface listener started \
  on 0.0.0.0:4723

如果你在Appium上添加了参数，他们会在日志中展示，如果添加了defaultCapabilities，日志也会显示出来。

Appium参数：http://appium.io/docs/en/writing-running-appium/server-args/
defaultCapabilities详见： http://appium.io/docs/en/writing-running-appium/default-capabilities-arg/

$ appium --address 172.19.131.113 --port 8000 --default-capabilities\
 '{"showIOSLog": true}'
[Appium] Welcome to Appium v1.8.0-beta3 \
    (REV 40e40975ebd3593d08c3f83de2546258f7ddf11d)
[Appium] Non-default server args:
[Appium] address: 172.19.131.113
[Appium] port: 8000
[Appium] defaultCapabilities: {
[Appium] showIOSLog: true
[Appium] }
[Appium] Default capabilities, which will be \
    added to each request unless overridden by desired capabilities:
[Appium] showIOSLog: true
[Appium] Appium REST http interface listener \
    started on 172.19.131.113:8000

对于自动化测试来说，这个信息很重要，因为不同的Appium版本有不同的功能和问题，必须要知道自己的Appium版本。

1.2 Session 日志

为了自动化测试跑起来，Session 要做很多事，日志提供了一些基本的session信息，特别是desired capabilities和default capabilities。应该时刻注意Appium服务是否正确接收了请求内容，日志列出了创建automation session（了解automation session看下面的链接）。

desired capabilities：http://appium.io/docs/en/writing-running-appium/caps/

[Appium] Creating new XCUITestDriver (v2.68.0) session
[Appium] Capabilities:
[Appium] app: /Users/isaac/apps/UICatalog-iphonesimulator.app
[Appium] platformName: iOS
[Appium] platformVersion: 11.3
[Appium] deviceName: iPhone 6
[Appium] automationName: XCUITest
[Appium] noReset: true
[Appium] maxTypingFrequency: 30
[Appium] clearSystemFiles: true
[Appium] showXcodeLog: false
[debug] [BaseDriver]
[debug] [BaseDriver] Creating session with MJSONWP \ 
    desired capabilities: {"app":"/Users/isaac/code/a...

上面的日志创建了一个XCUITestDriver session，设置了Capabilities参数包括app,platformName,platformVersion,deviceName,automationName等信息，以JSON的格式告诉AppiumServer一些被测试设备的一些重要信息。

1.3 Appium GET请求的日志

Appium 是一个 REST 服务，接收 HTTP 请求，展示请求内容，返回某种结果。Appium服务端日志用线和箭头展示了请求和返回的内容。在两个箭头之间是Appium服务端执行请求命令的日志信息：

什么是REST服务：https://en.wikipedia.org/wiki/Representational_state_transfer

[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

“-->”代表发出HTTP请求，“<--”代表返回请求的结果，中间是指令细节。使用MJSONWP(Mobile JSON Wire Protocol协议)去调用AppiumDriver.getStatus( )这个方法带着空列表作为参数，返回给客户端result:信息，整个过程耗时121毫秒，传输了126个字节。

2. 通过日志进行错误排查

利用日志可以非常方便的排查错误，错误通常发生在automation session之后，但有时，如果session持续存在，错误也可能发生。所以第一步是找出错误位置，下面的例子可以看出，每个指令用 [HTTP] --> 和 [HTTP] <-- 标记。这些标记之间是指令细节，包含了错误输出：

[HTTP] --> POST /wd/hub/session
<SNIP>
[debug] [AndroidDriver] Shutting down Android driver
[debug] [AndroidDriver] Called deleteSession but bootstrap wasn't active
[debug] [Logcat] Stopping logcat capture
[debug] [ADB] Getting connected devices...
[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)
at GeneratorFunctionPrototype.prototype.(anonymous function) [as throw] \
(/home/linuxbrew/.linuxbrew/lib/node_modules/appium/node_modules/\
babel-runtime/regenerator/runtime.js:100:21)
at GeneratorFunctionPrototype.invoke (/home/linuxbrew/.linuxbrew/\
lib/node_modules/appium/node_modules/babel-runtime/regenerator\
/runtime.js:136:37)
at <anonymous>
at process._tickCallback (internal/process/next_tick.js:188:7)
[HTTP] <-- POST /wd/hub/session 500 40811 ms - 557

用户试图用Android driver启动一个session，但发生了错误。Appium为准备 session 而关掉并清除AUT时发现了错误，这个错误让我们知道两件事：“Appium正在尝试做什么”，“哪里出错了”。

在这个例子中，Appium 尝试运行adb命令（adb shell am force-stop），adb 参数在错误信息中也有显示。发生了Android系统权限错误。此时，我们可以手动运行这个adb命令，看看错误是不是可以重现。如果错误重现，上网查错吧！如果adb命令成功运行，可能是Appium的bug，应该去Github的issue上查看或者提交这个bug。（例子中的错误是设备制造商的安全模型造成的）

这个例子只是众多错误中的一个，但它说明至关重要的一点，当错误发生时，日志可以提供更多的信息，如果没有完整的日志信息，对Appium排错难上加难。