Appium 服务器运行时会产生很多日志，但是很多人并不了解其中的意义，也无法掌握有用的信息。本文将详细解读如何读懂 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 版本。

创建 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...

Appium 指令

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 200121 ms - 126

错误排查

利用日志可以非常方便的排查错误，错误通常发生在 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 时发现了错误，这个错误让我们知道两件事：

1. Appium 正在尝试做什么

2. 哪里出错了

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

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

可以改变日志输出的参数

通常，默认的日志内容已经足够，如果你想去 Github 上寻求帮助，信息当然越多越好！下面一些参数可以改变 Appium 服务端的日志行为：

• --log-level - 改变Appium日志显示级别。

Appium 默认展示所有日志，它有以下一些选项：'info', 'info:debug', 'info:info', 'info:warn', 'info:error', 'warn', 'warn:debug', 'warn:info', 'warn:warn', 'warn:error', 'error', 'error:debug', 'error:info', 'error:warn', 'error:error', 'debug', 'debug:debug', 'debug:info', 'debug:warn', 'debug:error'。

• --log-no-colors - 如果你的控制台没有颜色（日志可能会产生一些奇怪的字符，比如"TODO: find the color"），你可以用这个参数关闭颜色。

• --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: true2018-03-15 13:17:58:732 - [Appium] Appium REST http interface listener started on 0.0.0.0:4723

58appiumexecuting排查

END