Edition 53

Accessing Android Logcat Logs with Appium

An Android device or emulator records detailed system logs, which can sometimes contain information which is pertinent to a test. Maybe our test failed and we want to see if our app logged an error to the system. Or maybe the only way to assert that our test succeeds is to make sure a particular pattern appears in the logs.

Android systems make these logs available using a tool called logcat, and Appium clients can access these logs remotely.

Both Appium and Selenium respond to the following JSON Wire Protocol endpoints:

GET /wd/hub/session/:sessionId/log/types
POST /wd/hub/session/:sessionId/log

Which can be called using the following methods in the Java client:

driver.manage().logs().getAvailableLogTypes();
driver.manage().logs().get("logcat");

The Python client and WebdriverIO call the same methods this way:

driver.log_types # note this is a property, not a function
driver.get_log('logcat')
driver.getLogTypes()
driver.getLogs('logcat')

The first method returns a collection of Strings which represent the logs which Appium provides. We are looking for "logcat" logs, but notice that Appium also provides android bug report data.

The logs are returned as a LogEntries class which implements the java.lang.Iterable interface. A single LogEntry object has toString() and toJson() methods, as well as some methods to get individual parts of the message such as timestamp or log level.

Something interesting to note is that every call to logs().get("logcat") will only return log entries since the last time logs().get("logcat") was called. The beginning of the system logs are only returned on the first call to logs().get("logcat"). The example code at the end of this post demonstrates this.

If we are running many tests over and over on the same device, it could be difficult to locate the point in the logs where our test ran (and maybe failed). If we wanted to address this, one strategy could be to call logs().get("logcat") at the beginning of each test. That way, when code inside the test gets logs, only logs which were recorded after the test started will be included.

@Before
public void consumeIrrelevantLogs() {
    driver.manage().logs().get("logcat");
}

There is also a desired capability we can set which clears the logcat logs at the start of a session.

driver.setCapability("clearDeviceLogsOnStart", true);

The following example code shows how we can get the supported log types for our test session. Then we get all logcat logs, printing the first and last lines. We wait 5 seconds and then print the first ten lines returned again, demonstrating that instead of starting from the beginning of the system log, the second call resumes from where the first left off.

import io.appium.java_client.AppiumDriver;
import org.junit.After;
import org.junit.Assert;
import org.junit.Before;
import org.junit.Test;
import org.openqa.selenium.logging.LogEntries;
import org.openqa.selenium.remote.DesiredCapabilities;

import java.io.IOException;
import java.net.URL;
import java.util.Set;
import java.util.stream.StreamSupport;

public class Edition053_ADB_Logcat {

    private String APP = "https://github.com/cloudgrey-io/the-app/releases/download/v1.8.1/TheApp-v1.8.1.apk";

    private AppiumDriver driver;

    @Before
    public void setUp() throws IOException {
        DesiredCapabilities caps = new DesiredCapabilities();

        caps.setCapability("platformName", "Android");
        caps.setCapability("deviceName", "Android Emulator");
        caps.setCapability("automationName", "UiAutomator2");
        caps.setCapability("app", APP);

        driver = new AppiumDriver(new URL("http://localhost:4723/wd/hub"), caps);
    }

    @After
    public void tearDown() {
        try {
            driver.quit();
        } catch (Exception ign) {}
    }

    @Test
    public void captureLogcat() {
        // inspect available log types
        Set<String> logtypes = driver.manage().logs().getAvailableLogTypes();
        System.out.println("suported log types: " + logtypes.toString()); // [logcat, bugreport, server, client]

        // print first and last 10 lines of logs
        LogEntries logs = driver.manage().logs().get("logcat");
        System.out.println("First and last ten lines of log: ");
        StreamSupport.stream(logs.spliterator(), false).limit(10).forEach(System.out::println);
        System.out.println("...");
        StreamSupport.stream(logs.spliterator(), false).skip(logs.getAll().size() - 10).forEach(System.out::println);

        // wait for more logs
        try { Thread.sleep(5000); } catch (Exception ign) {} // pause to allow visual verification

        // demonstrate that each time get logs, we only get new logs
        // which were generated since the last time we got logs
        LogEntries secondCallToLogs = driver.manage().logs().get("logcat");
        System.out.println("\nFirst ten lines of next log call: ");
        StreamSupport.stream(secondCallToLogs.spliterator(), false).limit(10).forEach(System.out::println);

        Assert.assertNotEquals(logs.iterator().next(), secondCallToLogs.iterator().next());
    }
}

This edition of AppiumPro also comes with Python and Javascript examples:

Python:

import unittest
import time
from appium import webdriver

class Edition053_ADB_Logcat(unittest.TestCase):

    def setUp(self):
        desired_caps = {}
        desired_caps['platformName'] = 'Android'
        desired_caps['automationName'] = 'UiAutomator2'
        desired_caps['deviceName'] = 'Android Emulator'
        desired_caps['app'] = 'https://github.com/cloudgrey-io/the-app/releases/download/v1.8.1/TheApp-v1.8.1.apk'

        self.driver = webdriver.Remote('http://localhost:4723/wd/hub', desired_caps)

    def tearDown(self):
        # end the session
        self.driver.quit()

    def test_capture_logcat(self):
        # inspect available log types
        logtypes = self.driver.log_types
        print(' ,'.join(logtypes)) #

        # print first and last 10 lines of logs
        logs = self.driver.get_log('logcat')
        log_messages = list(map(lambda log: log['message'], logs))
        print('First and last ten lines of log: ')
        print('\n'.join(log_messages[:10]))
        print('...')
        print('\n'.join(log_messages[-9:]))

        # wait for more logs
        time.sleep(5)

        # demonstrate that each time get logs, we only get new logs
        # which were generated since the last time we got logs
        logs = self.driver.get_log('logcat')
        second_set_of_log_messages = list(map(lambda log: log['message'], logs))
        print('\nFirst ten lines of second log call: ')
        print('\n'.join(second_set_of_log_messages[:10]))

        assert log_messages[0] != second_set_of_log_messages[0]

if __name__ == '__main__':
    suite = unittest.TestLoader().loadTestsFromTestCase(Edition053_ADB_Logcat)
    unittest.TextTestRunner(verbosity=2).run(suite)

Javascript:

let test = require('ava')
let { remote } = require('webdriverio')
let B = require('bluebird')

let driver

test.before(async t => {
  driver = await remote({
    hostname: 'localhost',
    port: 4723,
    path: '/wd/hub',
    capabilities: {
      platformName: 'Android',
      deviceName: 'Android Emulator',
      automationName: 'UiAutomator2',
      app: 'https://github.com/cloudgrey-io/the-app/releases/download/v1.8.1/TheApp-v1.8.1.apk'
    },
    logLevel: 'error'
  })
})

test.after(async t => {
  await driver.deleteSession()
})

test('capture logcat', async t => {
  // inspect available log types
  let logtypes = await driver.getLogTypes()
  console.log('supported log types: ', logtypes) // [ 'logcat', 'bugreport', 'server' ]

  // print first and last 10 lines of logs
  let logs = await driver.getLogs('logcat')
  console.log('First and last ten lines of logs:')
  console.log(logs.slice(0, 10).map(entry => entry.message).join('\n'))
  console.log('...')
  console.log(logs.slice(-10).map(entry => entry.message).join('\n'))

  // wait for more logs
  await B.delay(5000)

  // demonstrate that each time get logs, we only get new logs
  // which were generated since the last time we got logs
  let secondCallToLogs = await driver.getLogs('logcat')
  console.log('First ten lines of next log call: ')
  console.log(secondCallToLogs.slice(0, 10).map(entry => entry.message).join('\n'))

  t.true(logs[0].message !== secondCallToLogs[0].message)
})

(All three versions of the full code demonstration are available on GitHub)