Software testing/test development丨Appium problem analysis and positioning of app automation testing

Public account search: TestingStudio Hogwarts test development dry goods are very hardcore

When using Appium for testing, a large number of logs will be generated. Once an error is reported during the running process, you can analyze and troubleshoot the problem through the logs of the Appium server and the client.

Appium Server log – open service

Start the Appium Server through the command line. Let’s analyze the startup log. The first line of the log shows the Appium version information and the local running address of the service.

$ 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

If parameters are added when starting the Appium service, it will be displayed in the startup log. For example, if defaultCapabilities is added, the startup log will also be displayed.

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 arguments: http://appium.io/docs/en/writing-running-appium/server-args/

  • For details on defaultCapabilities: http://appium.io/docs/en/writing-running-appium/default-capabilities-arg/

Session log at runtime

After the automated test runs, the log of Appium Server provides some basic Session information, especially the configuration information of desired capabilities. You should always pay attention to whether the Appium service receives the request content correctly.

...
[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] },
...

The above log creates a Session, sets the Capabilities parameter, and tells AppiumServer some important information about the device under test in JSON format.

Log of Appium GET request

Appium is a REST service that receives HTTP requests and returns results. Appium server logs use [HTTP] --> and [HTTP] <-- to show the request and the returned information.

[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

"–>" means to send an HTTP request, "<–" means to respond, and the middle is the instruction details. [MJSONWP] refers to using MJSONWP (Mobile JSON Wire Protocol), calling the AppiumDriver.getStatus( ) method (without parameters), returning result information to the client, the whole process It took 121 milliseconds and 126 bytes were transferred.

Troubleshooting errors through logs

It is very easy to troubleshoot and locate the problem by using the log. The problem usually occurs after the automation Session. If the Session persists, errors may also occur.

[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 started Session , an error occurred while cleaning up com.company.app . This error lets us know two things: “what Appium is trying to do”, and “what went wrong”.

In this example, Appium tries to run the adb command (adb shell am force-stop), and the adb parameters are also shown in the error message. An Android system permission error has occurred. At this point, you can manually run this adb command to see if the error can be reproduced. If the error recurs, you can locate the problem by the error type.

This example is just one of many errors, but it illustrates an important point. When an error occurs, the log can provide more information. Without the complete log information, it is very difficult to troubleshoot Appium.

Change log output parameters

The following parameters can change the logging behavior of the Appium server:

–log-level: Change the Appium log display level. Appium shows all logs by default
, which has the following options: ‘info’, ‘info:debug’, ‘info:info’, ‘info:warn’, ‘info:error’, …

–log-no-colors: turn off the color, if the log is colored, strange characters may appear, such as “TODO: find the color”, you can use this parameter to turn off the color.

–log-timestamp: add a timestamp before the log

The display is as follows:

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