1401048 - Travis intermittent Selenium TimeoutException in test_basics.py's test_perfherder_main

Status: RESOLVED FIXED

(Tree Management :: Treeherder, defect, P1)

Description

[Ed Morley [:emorley]]

From the Travis selenium chunk.

I seem to recall seeing intermittent failures before now (though Will then landed some fixes for them), but the rate has definitely increased recently. Perhaps related to the geckodriver 0.19 update? (Bug 1400539)

The test in question:
https://github.com/mozilla/treeherder/blob/6a9eecfc4b7a993313a6ca2eaa9c9c4e44427996/tests/selenium/test_basics.py#L43-L45


"""

$ py.test tests/selenium/ --runselenium --driver Firefox
============================= test session starts ==============================
platform linux2 -- Python 2.7.13, pytest-3.2.2, py-1.4.34, pluggy-0.4.0
driver: Firefox
sensitiveurl: .*
Django settings: tests.settings (from ini file)
rootdir: /home/travis/build/mozilla/treeherder, inifile: setup.cfg
plugins: variables-1.7.0, selenium-1.11.1, django-3.1.2, base-url-1.4.1
collected 3 items                                                               

tests/selenium/test_basics.py .F.

=================================== FAILURES ===================================

_____________________________ test_perfherder_main _____________________________

initial_data = None
live_server = <LiveServer listening at http://localhost:54738>
selenium = <selenium.webdriver.firefox.webdriver.WebDriver (session="ebb9e088-5266-4e09-9de6-11866f93a894")>

    def test_perfherder_main(initial_data, live_server, selenium):
        '''
        This tests that the basic graphs view load and we can click the add tests button
        '''
        selenium.get(live_server.url + '/perf.html')
        add_test_button = WebDriverWait(selenium, 20).until(
            EC.visibility_of_element_located((By.ID, 'add-test-data-button'))
        )
        add_test_button.click()
        WebDriverWait(selenium, 20).until(
>           EC.presence_of_element_located((By.ID, 'performance-test-chooser'))
        )

tests/selenium/test_basics.py:44: 

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <selenium.webdriver.support.wait.WebDriverWait (session="ebb9e088-5266-4e09-9de6-11866f93a894")>
method = <selenium.webdriver.support.expected_conditions.presence_of_element_located object at 0x7f2dc4abe050>
message = ''

    def until(self, method, message=''):
        """Calls the method provided with the driver as an argument until the \
            return value is not False."""
        screen = None
        stacktrace = None
    
        end_time = time.time() + self._timeout
        while True:
            try:
                value = method(self._driver)
                if value:
                    return value
            except self._ignored_exceptions as exc:
                screen = getattr(exc, 'screen', None)
                stacktrace = getattr(exc, 'stacktrace', None)
            time.sleep(self._poll)
            if time.time() > end_time:
                break
>       raise TimeoutException(message, screen, stacktrace)
E       TimeoutException: Message:

../../../venv/lib/python2.7/site-packages/selenium/webdriver/support/wait.py:80: TimeoutException

---------------------------- Captured stdout setup -----------------------------
Installed 121 object(s) from 5 fixture(s)
------------------------------- pytest-selenium --------------------------------
URL: http://localhost:54738/perf.html#/graphs
Driver log: /tmp/pytest-of-travis/pytest-0/test_perfherder_main0/driver.log
WARNING: Failed to gather log types: Message: GET /session/ebb9e088-5266-4e09-9de6-11866f93a894/log/types did not match a known command

=============================== warnings summary ===============================
tests/selenium/test_basics.py::test_treeherder_main
  /home/travis/venv/lib/python2.7/site-packages/django/db/backends/mysql/base.py:101: Warning: ('124', 'InnoDB rebuilding table to add column FTS_DOC_ID')
    return self.cursor.execute(query, args)
  /home/travis/venv/lib/python2.7/site-packages/_pytest/warnings.py:88: UnicodeWarning: Warning is using unicode non convertible to ascii, converting to a safe representation:
    /home/travis/venv/lib/python2.7/site-packages/django/db/backends/mysql/base.py:101: Warning: ('124', 'InnoDB rebuilding table to add column FTS_DOC_ID')
    return self.cursor.execute(query, args)
  
    UnicodeWarning)

-- Docs: http://doc.pytest.org/en/latest/warnings.html
=============== 1 failed, 2 passed, 2 warnings in 45.75 seconds ================

The command "py.test tests/selenium/ --runselenium --driver Firefox" exited with 1.

"""

Comment 1

[Ed Morley [:emorley]]

I haven't seen this recently.

Comment 2

[Ed Morley [:emorley]]

This is happening again:
https://travis-ci.org/mozilla/treeherder/jobs/297247467

Comment 3

[Ed Morley [:emorley]]

I've performed some comparisons on Travis to narrow this down:
* master: 3 passes out of 14 runs
* with headless change reverted: 14 passes out of 14 runs
* master but using Firefox beta rather than stable: 12 passes out of 14 runs

Seeing that this test was intermittent in the past, I'm presuming this isn't the fault of headless per-se, but just a timing issue. As such, I'll open a bug to switch us to using beta (seeing as I think that's probably a better choice for us than stable anyway), which will at least improve the intermittentency rate significantly in the meantime.

Comment 4

[Ed Morley [:emorley]]

This was improved further in bug 1340305.