When Can The Test Blink?

January 26, 2021

•

By Gleb Bahmutov

Let's take a page where a loading element is displayed while the application is fetching the data from the server. If the test is observing the loading element to make sure it disappears, can the loading be too fast? Can the test runner "blink" and miss the element?

Yes, it can. In this blog post I will show an example of a flaky test where this happens. You can find the source code for this post in the repository bahmutov/cypress-blink-example.

The loading element test

Let's write a test to visit the local web application, ensure the loading element appears, then disappears. The test finishes by checking the expected number of items is present on the page.

describe('TodoMVC App', () => {
  it('shows loading element', () => {
    cy.visit('/?delay=500')
    cy.get('.loading').should('be.visible')
    cy.get('.loading').should('not.be.visible')
    cy.get('li.todo').should('have.length', 2)
  })
})

The test above first uses the positive assertion .should('be.visible') to establish the element is displayed, then the negative assertion .should('not.be.visible') to make sure the element goes away. We need the positive assertion first to make sure the test does not pass before the application starts data load. For more on negative assertions read the blog post Be Careful With Negative Assertions.

Note: the example application delays the data fetching if there is the ?delay=N URL parameter. This makes the test easier to explain and understand.

The passing loading element test

The test passes, but once in a while we see it fail, and sometimes it fails on continuous integration service. The video below shows the test pass, then fail when I click the "R" key to re-run the tests.

The loading element first passes, then fails on the second run

What is going on?

Run the test multiple times

First, let's make the test fail faster. The loading element should become visible after at most 500ms, thus there is no point to wait for 4 seconds (the default command timeout) before the test fails.

describe('TodoMVC App', () => {
  it('shows loading element', () => {
    cy.visit('/?delay=500')
    cy.get('.loading', { timeout: 800 }).should('be.visible')
    cy.get('.loading').should('not.be.visible')
    cy.get('li.todo').should('have.length', 2)
  })
})

Now let us see how often the test fails. We can run the test N times to see the failure rate. I will use the bundled Lodash to repeat the callback function N times to define N tests.

describe('TodoMVC App', () => {
  Cypress._.times(20, (k) => {
    it(`shows loading element ${k}`, () => {
      cy.visit('/?delay=500')
      cy.get('.loading', { timeout: 800 }).should('be.visible')
      cy.get('.loading').should('not.be.visible')
      cy.get('li.todo').should('have.length', 2)
    })
  })
})

The 20 tests run and fail 7 times = about 1/3 failure rate!

Typically, if the rate is very low, I would enable test retries and call it a day. But in our case the test has a fundamental flaw that we should not "overlook" by retrying.

It is the loading speed

If we observe a passing test we can see the loading element appearing and disappearing very quickly. Let us time how long it takes to fetch JSON data from the server. I will modify the application's code, and the elapsed time will be printed in the console.

loadTodos({ commit, state }) {
  console.log('loadTodos start, delay is %d', state.delay)
  setTimeout(() => {
    commit('SET_LOADING', true)
    const loadingStarted = Number(new Date())

    axios
      .get('/todos')
      .then(r => r.data)
      .then(todos => {
        commit('SET_TODOS', todos)
        commit('SET_LOADING', false)
        const loadingStopped = Number(new Date())
        const loadingTook = loadingStopped - loadingStarted
        console.log('>>>loading took', loadingTook)
      })
      .catch(e => {
        console.error('could not load todos')
        console.error(e.message)
        console.error(e.response.data)
      })
  }, state.delay)
},

I will also add a console statement at the start of the test

it(`shows loading element ${k}`, () => {
  console.log('>>>test', k)
  cy.visit('/?delay=500')
  ...
})

Let's run the test - we can filter the console logs using ">>>" string to show the test index and the loading duration messages only.

duration in each test with failing tests marked

Notice a curious thing: every failed test had the loading durations of just 15-16ms, while every successful test had the loading durations of longer than 24ms. Could the test runner be fooled by the fast sequence of the element appearing and disappearing?

To verify the minimum loading duration the application can have without failing the test, let's just return a mock data from the application after a certain delay, without actually fetching the data from the server.

setTimeout(() => {
  const todos = [
    { id: '1', title: 'first' },
    { id: '2', title: 'second' },
  ]
  commit('SET_TODOS', todos)
  commit('SET_LOADING', false)
  const loadingStopped = Number(new Date())
  const loadingTook = loadingStopped - loadingStarted
  console.log('>>>loading took', loadingTook)
}, 10)

The majority of tests now have a loading time of below 15ms, and are thus failing (of course any JavaScript timer set below 15 ms might take longer, thus there are still passing tests when the event loop was busy, and callback ran after longer period)

If we slow down the loading on the other hand, the tests reliably pass. The timeout of 20ms makes the tests solid green.

Test retries speed

When a Cypress test retries a command plus assertion combination, how quick is it? When the test checks for the loading element to be visible - how often does the assertion run? Let's find out.

Instead of cy.get('.loading').should('be.visible') let's run a .should(cb) assertion and measure the elapsed time between the callback execution timestamps.

it(`shows loading element ${k}`, () => {
  console.log('>>>test', k)
  cy.visit('/?delay=500')
  let previous = Number(new Date())
  cy.get('.loading', { timeout: 800 }).should(($el) => {
    const current = Number(new Date())
    const elapsed = current - previous
    console.log('>>>should', elapsed)
    previous = current
    expect($el).to.be.visible
  })
  cy.get('.loading').should('not.be.visible')
  cy.get('li.todo').should('have.length', 2)
})

Running the tests shows about 21+ ms between the assertion callback function executions.

Thus any DOM element that appears and disappears between 21ms intervals can become invisible to the test. Blink and you miss it!

Aside from the failing test, the elements that are too quick can also be invisible in the video of the test run. After all, a standard 30 frames per second video has video frames spaced 33ms apart.

Fixing the test

Let's fix our test - and not by modifying the application's code, but by slowing down the network request to reliably see the loading indicator. Notice that we need to slow down the loading request in this test only because other tests we might have do not look for the loading indicator, and thus do not care about its speed.

I will use the cy.intercept command to return a fixture file, delayed by a few hundred milliseconds. This should make the application consistently show the loading element.

it(`shows loading element ${k}`, () => {
  console.log('>>>test', k)
  cy.intercept('/todos', {
    fixture: 'todos.json',
    delayMs: 1000,
  })
  cy.visit('/?delay=500')
  cy.get('.loading', { timeout: 800 }).should('be.visible')
  cy.get('.loading').should('not.be.visible')
  cy.get('li.todo').should('have.length', 2)
})

As you can see from the end of the test run, all tests are green, and all is good in the world.

Happy testing!

Read more