Merge pull request #209 from edx/jmbowman/TE-2635

TE-2635 More logging on test failures, v0.8.0

Author: jmbowman

.travis.yml

@@ -3,7 +3,6 @@ python:
  - '2.7'
  - '3.5'
  - '3.6'
- - 'pypy'
 sudo: false
 branches:
   only:

CHANGELOG

@@ -1,3 +1,9 @@
+v0.8.0 (07/18/18)
+* Preserve geckodriver log for Firefox test failures
+* Better handling of screenshot and log directory settings
+* Log more information on page load failures
+* Python 3.6 support
+
 v0.7.3 (05/21/18)
 * Modified wait for page logic
 

bok_choy/browser.py

@@ -2,20 +2,22 @@
 Use environment variables to configure Selenium remote WebDriver.
 For use with SauceLabs (via SauceConnect) or local browsers.
 """
-from __future__ import absolute_import
+from __future__ import absolute_import, print_function
 
-import os
+import errno
 import logging
-from json import dumps
+import os
 import socket
-import errno
+from json import dumps
+from shutil import copyfile
 
 from needle.driver import (NeedleFirefox, NeedleChrome, NeedleIe,
                            NeedleSafari, NeedlePhantomJS, NeedleOpera)
 from selenium import webdriver
 from selenium.common.exceptions import WebDriverException
-from selenium.webdriver.chrome.options import Options
+from selenium.webdriver.chrome.options import Options as ChromeOptions
 from selenium.webdriver.firefox.firefox_binary import FirefoxBinary
+from selenium.webdriver.firefox.options import Options as FirefoxOptions
 
 from bok_choy.promise import Promise
 
@@ -109,9 +111,13 @@ def save_screenshot(driver, name):
         None
     """
     if hasattr(driver, 'save_screenshot'):
-        image_name = os.path.join(
-            os.environ.get('SCREENSHOT_DIR'), name + '.png'
-        )
+        screenshot_dir = os.environ.get('SCREENSHOT_DIR')
+        if not screenshot_dir:
+            LOGGER.warning('The SCREENSHOT_DIR environment variable was not set; not saving a screenshot')
+            return
+        elif not os.path.exists(screenshot_dir):
+            os.makedirs(screenshot_dir)
+        image_name = os.path.join(screenshot_dir, name + '.png')
         driver.save_screenshot(image_name)
 
     else:
@@ -139,16 +145,28 @@ def save_driver_logs(driver, prefix):
         None
     """
     browser_name = os.environ.get('SELENIUM_BROWSER', 'firefox')
-    if browser_name == "firefox":
+    log_dir = os.environ.get('SELENIUM_DRIVER_LOG_DIR')
+    if not log_dir:
+        LOGGER.warning('The SELENIUM_DRIVER_LOG_DIR environment variable was not set; not saving logs')
+        return
+    elif not os.path.exists(log_dir):
+        os.makedirs(log_dir)
+    if browser_name == 'firefox':
+        # Firefox doesn't yet provide logs to Selenium, but does log to a separate file
+        # https://github.com/mozilla/geckodriver/issues/284
+        # https://firefox-source-docs.mozilla.org/testing/geckodriver/geckodriver/TraceLogs.html
+        log_path = os.path.join(os.getcwd(), 'geckodriver.log')
+        if os.path.exists(log_path):
+            dest_path = os.path.join(log_dir, '{}_geckodriver.log'.format(prefix))
+            copyfile(log_path, dest_path)
         return
 
     log_types = ['browser', 'driver', 'client', 'server']
     for log_type in log_types:
         try:
             log = driver.get_log(log_type)
             file_name = os.path.join(
-                os.environ.get('SELENIUM_DRIVER_LOG_DIR'), '{}_{}.log'.format(
-                    prefix, log_type)
+                log_dir, '{}_{}.log'.format(prefix, log_type)
             )
             with open(file_name, 'w') as output_file:
                 for line in log:
@@ -345,9 +363,17 @@ def _local_browser_class(browser_name):
                 name=browser_name, options=", ".join(list(BROWSERS.keys()))))
     else:
         if browser_name == 'firefox':
+            # Remove geckodriver log data from previous test cases
+            log_path = os.path.join(os.getcwd(), 'geckodriver.log')
+            if os.path.exists(log_path):
+                os.remove(log_path)
+
+            firefox_options = FirefoxOptions()
+            firefox_options.log.level = 'trace'
             browser_args = []
             browser_kwargs = {
                 'firefox_profile': _firefox_profile(),
+                'options': firefox_options,
             }
 
             firefox_path = os.environ.get('SELENIUM_FIREFOX_PATH')
@@ -367,7 +393,7 @@ def _local_browser_class(browser_name):
                 })
 
         elif browser_name == 'chrome':
-            chrome_options = Options()
+            chrome_options = ChromeOptions()
 
             # Emulate webcam and microphone for testing purposes
             chrome_options.add_argument('--use-fake-device-for-media-stream')

bok_choy/page_object.py

@@ -328,6 +328,7 @@ def visit(self):
         try:
             self.browser.get(self.url)
         except (WebDriverException, socket.gaierror):
+            LOGGER.warning(u"Unexpected page load exception:", exc_info=True)
             raise PageLoadError("Could not load page '{!r}' at URL '{}'".format(
                 self, self.url
             ))
@@ -361,7 +362,11 @@ def validate_url(cls, url):
         result = urllib_parse.urlsplit(url)
 
         # Check that we have a protocol and hostname
-        if not result.scheme or not result.netloc:
+        if not result.scheme:
+            LOGGER.warning(u"%s is missing a protocol", url)
+            return False
+        if not result.netloc:
+            LOGGER.warning(u"%s is missing a hostname", url)
             return False
 
         # Check that the port is an integer
@@ -370,8 +375,10 @@ def validate_url(cls, url):
                 int(result.port)
             elif result.netloc.endswith(':'):
                 # Valid URLs do not end with colons.
+                LOGGER.warning(u"%s has a colon after the hostname but no port", url)
                 return False
         except ValueError:
+            LOGGER.warning(u"%s uses an invalid port", url)
             return False
         else:
             return True
@@ -440,7 +447,7 @@ def _is_document_ready():
                 "return document.readyState=='complete'")
 
         try:
-            # Wait for page to laod completely i.e. for document.readyState to become complete
+            # Wait for page to load completely i.e. for document.readyState to become complete
             EmptyPromise(
                 _is_document_ready,
                 "The document and all sub-resources have finished loading.",

setup.py

@@ -3,7 +3,7 @@
 import codecs
 from setuptools import setup
 
-VERSION = '0.7.3'
+VERSION = '0.8.0'
 DESCRIPTION = 'UI-level acceptance test framework'
 
 

tests/test_browser.py

@@ -207,11 +207,23 @@ def test_save_screenshot(self):
         # Check that the file is not empty
         assert os.stat(expected_file).st_size > 100
 
+    def test_save_screenshot_dir_not_set(self, caplog, monkeypatch):
+        browser = self.browser
+        monkeypatch.delenv('SCREENSHOT_DIR')
+        bok_choy.browser.save_screenshot(browser, 'empty')
+        assert 'The SCREENSHOT_DIR environment variable was not set; not saving a screenshot' in caplog.text
+
     def test_save_screenshot_unsupported(self, caplog):
         browser = 'Some driver without save_screenshot()'
         bok_choy.browser.save_screenshot(browser, 'button_page')
         assert 'Browser does not support screenshots.' in caplog.text
 
+    def test_save_driver_logs_dir_not_set(self, caplog, monkeypatch):
+        browser = self.browser
+        monkeypatch.delenv('SELENIUM_DRIVER_LOG_DIR')
+        bok_choy.browser.save_driver_logs(browser, 'empty')
+        assert 'The SELENIUM_DRIVER_LOG_DIR environment variable was not set; not saving logs' in caplog.text
+
     def test_save_driver_logs_unsupported(self):
         browser = self.browser
         tempdir_path = self.tempdir_path

tests/test_page_object.py

@@ -4,13 +4,23 @@
 
 from __future__ import absolute_import
 
+import logging
 from unittest import TestCase
 
+import pytest
 from mock import Mock
+from selenium.common.exceptions import WebDriverException
 
 from bok_choy.page_object import PageObject, PageLoadError, unguarded, WrongPageError
 from bok_choy.promise import BrokenPromise
-from tests.pages import SitePage
+from tests.pages import ButtonPage, SitePage
+
+
+class InvalidPortPage(SitePage):
+    """
+    Create a page that will return a URL with an invalid port.
+    """
+    url = "http://localhost:8o/invalid"
 
 
 class InvalidURLPage(SitePage):
@@ -20,11 +30,19 @@ class InvalidURLPage(SitePage):
     url = "http://localhost:/invalid"
 
 
+class MissingHostnamePage(SitePage):
+    """
+    Create a page that will return a URL with no hostname.
+    """
+    url = "http:///invalid"
+
+
 class NeverOnPage(SitePage):
     """
     Create a page that never successfully loads.
     """
     url = "http://localhost/never_on"
+    class_attr = ButtonPage
 
     def is_browser_on_page(self):
         return False
@@ -129,3 +147,51 @@ def test_visit_timeout(self):
         # If the page doesn't load before the timeout, PageLoadError is raised
         with self.assertRaises(PageLoadError):
             NeverOnPage(Mock()).visit()
+
+
+def test_invalid_port_exception(caplog):
+    with pytest.raises(PageLoadError):
+        InvalidPortPage(Mock()).visit()
+    assert u'uses an invalid port' in caplog.text
+
+
+def test_missing_hostname_exception(caplog):
+    with pytest.raises(PageLoadError):
+        MissingHostnamePage(Mock()).visit()
+    assert u'is missing a hostname' in caplog.text
+
+
+def test_never_loads(caplog):
+    attrs = {'execute_script.return_value': False}
+    browser = Mock(**attrs)
+    page = ButtonPage(browser)
+    with pytest.raises(BrokenPromise):
+        page.wait_for_page(timeout=1)
+    assert u'document.readyState does not become complete for following url' in caplog.text
+
+
+def test_page_load_exception(caplog):
+    attrs = {'get.side_effect': WebDriverException('Boom!')}
+    browser = Mock(**attrs)
+    page = ButtonPage(browser)
+    with pytest.raises(PageLoadError):
+        page.visit()
+    assert u'Unexpected page load exception' in caplog.text
+
+
+def test_retry_errors(caplog):
+    def promise_check_func():
+        """
+        Check function which continuously fails with a WebDriverException until timeout
+        """
+        raise WebDriverException('Boom!')
+    page = ButtonPage(Mock())
+    with pytest.raises(BrokenPromise):
+        page.wait_for(promise_check_func, 'Never succeeds', timeout=1)
+    assert u'Exception ignored during retry loop' in caplog.text
+
+
+def test_warning(caplog):
+    page = SitePage(Mock())
+    page.warning(u'Scary stuff')
+    assert ('SitePage', logging.WARN, u'Scary stuff') in caplog.record_tuples

tox.ini

@@ -27,7 +27,7 @@ commands =
     pycodestyle tests
     mkdir -p $SELENIUM_DRIVER_LOG_DIR
     rm -rf $SELENIUM_DRIVER_LOG_DIR/*
-    py.test {posargs:tests} --durations=10
+    pytest {posargs:tests} --durations=10
 
 [testenv:doc]
 deps =