Edition 88

Saving Test Data To Make Debugging Easier

When we're writing tests on our local machines, we're usually running just one Appium test at a time, with the server log window to one side to help us in case something goes wrong. We're also usually watching the test execute on the simulator or device (unless we've decided to take a coffee break at that moment). In this type of scenario, it's often pretty easy to diagnose a test failure, because we can see immediately that the test didn't proceed to the correct view, find the correct element, or whatever the issue might be.

Debugging in CI

This happy little scenario, however, is not typically the one we find ourselves when we actually need to debug something. We never commit failing tests to our build (right? right?), so when there's a build failure because of one of our tests, it's because something went wrong that we didn't expect. In this case, it's usually not just one test that ran, but many, and by the time we know of the failure, the test itself is long finished. At this point, we can't watch the test run, and unless we did something special to save it, we no longer have access to the Appium logs or any record of the app state at the time of failure.

So let's do that special something to make sure that we don't wind up in a horrible debugging situation with nothing to go on!

Capturing Debug Helpers

The basic idea here is that we want to inject some code into the test lifecycle, specifically in between test failure and cleaning up to move on to the next test. At this point in the test lifecycle, we know we've got a failed test, but we haven't yet quit our Appium session, so we still have access to a driver object. This is great, because (assuming the Appium session itself is still alive and working correctly), we can use it to retrieve all kinds of helpful diagnostic information about the session, which we can then save on disk for for later review should the need arise.

What do we want to save? That is of course up to us, but I'm proposing a basic set of 3 useful items:

  1. The Appium server logs --- these contain the log of everything Appium thinks it's doing with your session, so it's a great place to debug issues that might have something to do with Appium itself, or to go back and make sure everything happened as expected in the earlier phases of the session. If you're not sure what to do with the Appium server logs, or how to read them, check out Isaac Murchie's great AppiumConf 2018 talk on the subject.
  2. The app source --- especially if your error is of the "element not found" category, having the app/page source handy while investigating a test failure can be a great sanity check.
  3. A screenshot --- nothing beats seeing exactly what was on the device screen when your test failed. Was it an errant pop-up? Had the app crashed and gone away all together? A visual inspection can sometimes reveal the true cause of a test failure much more quickly than a scan of logs.

These are all in addition, of course, to the client/test log itself, which is output within the CI system and therefore easy to save one way or another.

To actually retrieve all this data, we simply need to use the appropriate Appium commands. Then it's up to us what to do with them. In this example, I'll just write them to stdout, assuming that all logging from the test output is being saved somewhere reasonable:

// print appium logs
LogEntries entries = driver.manage().logs().get("server");
System.out.println("======== APPIUM SERVER LOGS ========");
for (LogEntry entry : entries) {
    System.out.println(new Date(entry.getTimestamp()) + " " + entry.getMessage());
}
System.out.println("================");

// print source
System.out.println("======== APP SOURCE ========");
System.out.println(driver.getPageSource());
System.out.println("================");

// save screenshot
String testName = desc.getMethodName().replaceAll("[^a-zA-Z0-9-_\\.]", "_");
File screenData = driver.getScreenshotAs(OutputType.FILE);
try {
    File screenFile = new File(SCREEN_DIR + "/" + testName + ".png");
    FileUtils.copyFile(screenData, screenFile);
    System.out.println("======== SCREENSHOT ========");
    System.out.println(screenFile.getAbsolutePath());
    System.out.println("================");
} catch (IOException ign) {}

Once you strip away the gratuitous log printing, you'll see that the code above is pretty straightforward. The only complexity comes in retrieving the Appium server logs. On the client side, we use the log manager to retrieve logs of type server. Because Appium servers might plausibly handle sessions for multiple clients at a time, however, server log retrieval is not enabled by default as a potential information security risk.

If you run your own instance of Appium, you can turn on server log retrieval using the --allow-insecure flag:

appium --allow-insecure=get_system_logs

This will direct Appium not to complain if you attempt to get the system logs!

JUnit's TestWatcher

The question remains, though: where to put the code above? Each test framework has a different way of figuring out whether a test has failed and performing some actions before moving on to the next test. In JUnit, this is via the TestWatcher class. The way we use it is to create our own extension of this class, and override particular methods of TestWatcher pertaining to the aspects of the lifecycle where we want to inject code. Then we assign our new watcher class as a @Rule in our test class itself. From a skeletal perspective, it would look something like the following:

public class Edition088_Debugging_Aids {
    private IOSDriver driver;

    @Rule
    public DebugWatcher debugWatcher = new DebugWatcher();

    @Before
    public void setUp() throws MalformedURLException { /*...*/ }

    @Test
    public void testSomething() { /*...*/ }

    public class DebugWatcher extends TestWatcher {

        @Override
        protected void failed(Throwable e, Description desc) {
            // ---> this is where our debug print lines go! <---
        }

        @Override
        protected void finished(Description desc) {
            if (driver != null) {
                driver.quit();
            }
        }
    }
}

We can, as in the example above, define our watcher class right in our test class itself, if we want (but we don't have to). The important things are to (a) override the failed method and put all our debug handler code in it, and (b) override the finished method to act as our tear-down function, wherein we clean up the driver and anything else we need.

That's basically it! It's up to you to get creative with where you put the debug helper info retrieved from Appium--send it to an asset storage system? Build your own debug UI on top of it? Whatever you want.

Make sure to take a look at the full example on GitHub, with actual test logic filled out, so you can see how everything works when it's fully put together. Happy debugging (or at least, happi_er_ debugging)!