Is Robotium reliable for testing how fast activities and fragments start?

I'm trying to write black box automated tests to assert things like "ensure the landing page appears within 500ms of launching the app" and "ensure that a login takes less than 2 seconds". I want to do this by driving the UI of the real app, to simulate real users as closely as possible.

I'm using Robotium 5.0.1 for my black box UI tests, and I was hoping it would be simple to add some simple timing code. However, the tests seem to fail intermittently in different places, even in places that don't make network requests. It looks like occasional delays of ~2 seconds occur when running multiple tests locally in an emulator (we also run tests on Jenkins in the cloud using CloudBees, though I haven't tried the tests there yet).

Is Robotium the right tool to use for this sort of testing? Do you have any tips on the best way to do these kinds of tests?

Here's my test:

public void testLogin() {
    AppData.getAppData().clear();

    startTimer();
    launchActivity();
    assertTrue(solo.waitForFragmentByTag("landingfragment", 3000));
    stopTimer();
    assertWasQuickerThan(500);

    startTimer();
    solo.clickOnButton("Log In");
    assertTrue(solo.waitForFragmentByTag("loginfragment", 3000));
    stopTimer();
    assertWasQuickerThan(500);

    solo.enterText(0, TestUtils.EXISTING_USER_EMAIL);
    solo.enterText(1, TestUtils.EXISTING_USER_PASSWORD);

    startTimer();
    solo.clickOnButton("Next");
    assertTrue(solo.waitForActivity(LaunchActivity.class, 3000));
    stopTimer();
    assertWasQuickerThan(2000);
}

Here's the logcat (this shows the landing page appeared within 16ms, but after pressing the log in button it took 2079ms for the login page to appear):

03-12 14:46:11.535      386-571/system_process I/ActivityManager﹕ START u0 {cmp=com.example/com.example.ui.LaunchActivity} from pid 1180
03-12 14:46:11.555    1180-1193/com.example D/MyApp﹕ LoginTest: Step took 16ms to complete,
03-12 14:46:12.035    1180-1180/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed 1470K, 47% free 3456K/6424K, paused 96ms, total 98ms
03-12 14:46:12.045    1180-1180/com.example I/dalvikvm-heap﹕ Grow heap (frag case) to 4.842MB for 1463056-byte allocation
03-12 14:46:12.145    1180-1281/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed 5K, 25% free 4880K/6424K, paused 87ms, total 102ms
03-12 14:46:12.405      386-400/system_process I/ActivityManager﹕ Displayed com.example/com.example.ui.LaunchActivity: +848ms
03-12 14:46:13.115    1180-1180/com.example I/MyApp﹕ USER: LandingFragment: Sign in pressed,
03-12 14:46:13.315    1180-1180/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed 1478K, 46% free 3508K/6424K, paused 21ms, total 23ms
03-12 14:46:13.315    1180-1180/com.example I/dalvikvm-heap﹕ Grow heap (frag case) to 4.761MB for 1324816-byte allocation
03-12 14:46:13.345    1180-1180/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed 3K, 26% free 4798K/6424K, paused 23ms, total 23ms
03-12 14:46:13.395    1180-1180/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed <1K, 26% free 4798K/6424K, paused 31ms, total 31ms
03-12 14:46:13.405    1180-1180/com.example I/dalvikvm-heap﹕ Grow heap (frag case) to 6.153MB for 1463056-byte allocation
03-12 14:46:13.425    1180-1281/com.example D/dalvikvm﹕ GC_FOR_ALLOC freed 0K, 21% free 6227K/7856K, paused 26ms, total 26ms
03-12 14:46:13.445    1180-1180/com.example I/Choreographer﹕ Skipped 47 frames!  The application may be doing too much work on its main thread.
03-12 14:46:13.635    1180-1193/com.example D/MyApp﹕ LoginTest: Step took 2079ms to complete,
03-12 14:46:14.695    1180-1180/com.example I/Choreographer﹕ Skipped 52 frames!  The application may be doing too much work on its main thread.
03-12 14:46:15.325    1180-1193/com.example I/TestRunner﹕ failed: testLogin(com.example.blackbox.LoginTest)
03-12 14:46:15.335    1180-1193/com.example I/TestRunner﹕ ----- begin exception -----
03-12 14:46:15.335    1180-1193/com.example I/TestRunner﹕ junit.framework.AssertionFailedError: Step was too slow, expected 500ms but took 2079ms
            at junit.framework.Assert.fail(Assert.java:50)
            at junit.framework.Assert.assertTrue(Assert.java:20)
            at com.example.blackbox.BaseBlackBoxTest.assertWasQuickerThan(BaseBlackBoxTest.java:57)
            at com.example.blackbox.LoginTest.testLogin(LoginTest.java:52)

...and here is my BaseBlackBoxTest class that my test class extends:

abstract class BaseBlackBoxTest<T extends android.app.Activity>
        extends ActivityInstrumentationTestCase2<T> {

    protected Solo solo;

    protected long mStartTime;
    protected long mStopTime;

    @Before
    public void setUp() throws Exception {
        solo = new Solo(getInstrumentation(), getActivity());
    }

    @After
    public void tearDown() throws Exception {
        solo.finishOpenedActivities();
    }

    public BaseBlackBoxTest(Class clazz) {
        super(clazz);
    }

    protected void launchActivity() {
        Activity activity = getActivity();
        Intent intent = new Intent(activity, activity.getClass());
        activity.startActivity(intent);

        solo.assertCurrentActivity("Expecting " + activity.getClass(), activity.getClass());
    }

    // TIMING UTILITIES //

    protected void startTimer() {
        mStartTime = System.nanoTime();
    }

    protected void stopTimer() {
        mStopTime = System.nanoTime();
    }

    protected void assertWasQuickerThan(long maxDurationMillis) {
        long durationMillis = (mStopTime - mStartTime) / 1000000;
        LogIt.d(this, "Step took " + durationMillis + "ms to complete");
        assertTrue("Step was too slow, expected " + maxDurationMillis + "ms but took " + durationMillis + "ms",
                durationMillis < maxDurationMillis);
    }
}

Recommended topics

Hot tags