When the Appium server runs there is often a bewildering stream of logs, giving information about the automation in process, but the details are often obscure.
The first lines of the log announce the version of Appium, and the address it is running on:
Further, if you have started the server with any special flags, including default desired capabilities they will also be noted here, to help with understand the environment that is being run:
This information is invaluable for providing context to the test automation that will be run. In particular, different versions of Appium will have different capacities and issues, so knowing what version is running is necessary to begin to make any determination of what is going on in any run.
While session creation involves a complicated array of operations to get the environment set up and the application under test running, the beginning of the logs for a command to create the session provides basic information about the session. In particular, the desired capabilities, along with any default capabilities are listed. It is often useful to check that what was intended to be requested was actually received by the Appium server, since it is the capabilities listed here that will be acted upon for the automation session.
Appium is a REST server, accepting incoming HTTP requests, performing the action requested, and returning a result of some sort. In the Appium server logs, each such incoming request is delineated by a line indicating the request, and a line indicating the response. In between these are the details of the execution of the requested command:
Recommended post: Batching Appium Commands Using Execute Driver Script to Speed Up Tests
On the client-side errors are usually helpful, there is usually more information to be found in the logs. Usually, the errors will be at the end of the automation session, but sometimes the session can continue, and the error logs will be earlier. So, the first step is to identify the command where the error happened. As we have already seen, each command is marked by [HTTP] --> and [HTTP] <--. Within these markers is the details of the execution of the command, including any error output.
Let's take a look at a concrete example:
In this abridged set of logs, the user has attempted to start a session using the Android driver and has been met with an error. In this case it looks like the error happened during Appium's attempt to stop and clear the AUT in preparation for the session. Here the error gives us two important pieces of information:
- What Appium was trying to do, specifically
- What went wrong (in the form of error text and any related codes)
In this case, Appium was trying to run an adb command (adb shell am force-stop), with parameters that have been included in the error text. And what happened? It was met with an Android system error about permissions. At this point, we have everything we need to troubleshoot locally. We can run the adb command that Appium tried to run, for example, and determine whether we can reproduce the issue outside of Appium. If so, we can then seek recourse through a helpful Android-specific forum, or from other Appium users who might have run into the same problem. If the command can be run successfully from the command line, then it may be we have uncovered a bug in Appium, and it should be reported as a GitHub issue.
(If you're curious, in this case the user was able to reproduce the problem outside of Appium, so it appeared to be related to the specific device manufacturer's security model).
Obviously, this is one of many, many examples that could have been given, but it illustrates the core point that, when faced with an error, the logs can help provide more information that facilitate a local repro attempt or help the Appium team understand what could be going wrong. No issue should ever be submitted to the Appium issue tracker without a complete set of logs!
Server Flags for Changing the Logging Output
While the default logging output is often enough, and if you are opening an issue on GitHub to get help with a problem, the more information the better, there are server flags provided to change the logging behavior of the Appium server.
- --log-level - change the level at which Appium logs information. Appium defaults to logging everything, which can be a lot. The options for the flag are '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 - If your console does not display colors (this will be manifested as logs with odd character sequences like TODO: find the color) you can turn off colors with this flag
- --log-timestamp - Add a timestamp to the beginning of each log line, which is useful in cases where timeouts are occurring. The log lines will look like