Fix UnicodeEncodeError when logging non-ascii characters (Fixes #54)

toolium/behave/environment.py

@@ -107,7 +107,7 @@ def bdd_common_before_scenario(context_or_world, scenario):
     if context_or_world.driver and implicitly_wait:
         context_or_world.driver.implicitly_wait(implicitly_wait)
 
-    context_or_world.logger.info("Running new scenario: {0}".format(scenario.name))
+    context_or_world.logger.info("Running new scenario: %s", scenario.name)
 
 
 def create_and_configure_wrapper(context_or_world):
@@ -195,11 +195,11 @@ def bdd_common_after_scenario(context_or_world, scenario, status):
     elif status == 'passed':
         test_status = 'Pass'
         test_comment = None
-        context_or_world.logger.info("The scenario '{0}' has passed".format(scenario.name))
+        context_or_world.logger.info("The scenario '%s' has passed", scenario.name)
     else:
         test_status = 'Fail'
         test_comment = "The scenario '{0}' has failed".format(scenario.name)
-        context_or_world.logger.error(test_comment)
+        context_or_world.logger.error("The scenario '%s' has failed", scenario.name)
         # Capture screenshot on error
         DriverWrappersPool.capture_screenshots(scenario_file_name)
 

toolium/config_driver.py

@@ -19,13 +19,11 @@
 import ast
 import logging
 
-# Python 2 and 3 compatibility
-from six.moves.configparser import NoSectionError
-
 from appium import webdriver as appiumdriver
 from selenium import webdriver
 from selenium.webdriver.common.desired_capabilities import DesiredCapabilities
 from selenium.webdriver.firefox.options import Options
+from six.moves.configparser import NoSectionError  # Python 2 and 3 compatibility
 
 
 def get_error_message_from_exception(exception):
@@ -54,15 +52,14 @@ def create_driver(self):
         driver_type = self.config.get('Driver', 'type')
         try:
             if self.config.getboolean_optional('Server', 'enabled'):
-                self.logger.info("Creating remote driver (type = {0})".format(driver_type))
+                self.logger.info("Creating remote driver (type = %s)", driver_type)
                 driver = self._create_remote_driver()
             else:
-                self.logger.info("Creating local driver (type = {0})".format(driver_type))
+                self.logger.info("Creating local driver (type = %s)", driver_type)
                 driver = self._create_local_driver()
         except Exception as exc:
             error_message = get_error_message_from_exception(exc)
-            message = "{0} driver can not be launched: {1}".format(driver_type.capitalize(), error_message)
-            self.logger.error(message)
+            self.logger.error("%s driver can not be launched: %s", driver_type.capitalize(), error_message)
             raise
 
         return driver
@@ -189,7 +186,7 @@ def _add_capabilities_from_properties(self, capabilities, section):
         cap_type = {'Capabilities': 'server', 'AppiumCapabilities': 'Appium server'}
         try:
             for cap, cap_value in dict(self.config.items(section)).items():
-                self.logger.debug("Added {} capability: {} = {}".format(cap_type[section], cap, cap_value))
+                self.logger.debug("Added %s capability: %s = %s", cap_type[section], cap, cap_value)
                 capabilities[cap] = cap_value if cap == 'version' else self._convert_property_type(cap_value)
         except NoSectionError:
             pass
@@ -202,14 +199,14 @@ def _setup_firefox(self, capabilities):
         """
         if capabilities.get("marionette"):
             gecko_driver = self.config.get('Driver', 'gecko_driver_path')
-            self.logger.debug("Gecko driver path given in properties: {0}".format(gecko_driver))
+            self.logger.debug("Gecko driver path given in properties: %s", gecko_driver)
         else:
             gecko_driver = None
 
         # Get Firefox binary
         firefox_binary = self.config.get_optional('Firefox', 'binary')
         if firefox_binary:
-            self.logger.debug("Using firefox binary: {0}".format(firefox_binary))
+            self.logger.debug("Using firefox binary: %s", firefox_binary)
             firefox_options = Options()
             firefox_options.binary = firefox_binary
         else:
@@ -226,7 +223,7 @@ def _create_firefox_profile(self):
         # Get Firefox profile
         profile_directory = self.config.get_optional('Firefox', 'profile')
         if profile_directory:
-            self.logger.debug("Using firefox profile: {0}".format(profile_directory))
+            self.logger.debug("Using firefox profile: %s", profile_directory)
 
         # Create Firefox profile
         profile = webdriver.FirefoxProfile(profile_directory=profile_directory)
@@ -235,7 +232,7 @@ def _create_firefox_profile(self):
         # Add Firefox preferences
         try:
             for pref, pref_value in dict(self.config.items('FirefoxPreferences')).items():
-                self.logger.debug("Added firefox preference: {0} = {1}".format(pref, pref_value))
+                self.logger.debug("Added firefox preference: %s = %s", pref, pref_value)
                 profile.set_preference(pref, self._convert_property_type(pref_value))
             profile.update_preferences()
         except NoSectionError:
@@ -244,7 +241,7 @@ def _create_firefox_profile(self):
         # Add Firefox extensions
         try:
             for pref, pref_value in dict(self.config.items('FirefoxExtensions')).items():
-                self.logger.debug("Added firefox extension: {0} = {1}".format(pref, pref_value))
+                self.logger.debug("Added firefox extension: %s = %s", pref, pref_value)
                 profile.add_extension(pref_value)
         except NoSectionError:
             pass
@@ -277,7 +274,7 @@ def _setup_chrome(self, capabilities):
         :returns: a new local Chrome driver
         """
         chrome_driver = self.config.get('Driver', 'chrome_driver_path')
-        self.logger.debug("Chrome driver path given in properties: {0}".format(chrome_driver))
+        self.logger.debug("Chrome driver path given in properties: %s", chrome_driver)
         return webdriver.Chrome(chrome_driver, chrome_options=self._create_chrome_options(),
                                 desired_capabilities=capabilities)
 
@@ -307,7 +304,7 @@ def _add_chrome_options(self, options, option_name):
         option_value = dict()
         try:
             for key, value in dict(self.config.items(options_conf[option_name]['section'])).items():
-                self.logger.debug("Added chrome {}: {} = {}".format(options_conf[option_name]['message'], key, value))
+                self.logger.debug("Added chrome %s: %s = %s", options_conf[option_name]['message'], key, value)
                 option_value[key] = self._convert_property_type(value)
             if len(option_value) > 0:
                 options.add_experimental_option(option_name, option_value)
@@ -322,7 +319,7 @@ def _add_chrome_arguments(self, options):
         try:
             for pref, pref_value in dict(self.config.items('ChromeArguments')).items():
                 pref_value = '={}'.format(pref_value) if pref_value else ''
-                self.logger.debug("Added chrome argument: {0}{1}".format(pref, pref_value))
+                self.logger.debug("Added chrome argument: %s%s", pref, pref_value)
                 options.add_argument('{}{}'.format(pref, self._convert_property_type(pref_value)))
         except NoSectionError:
             pass
@@ -342,7 +339,7 @@ def _setup_opera(self, capabilities):
         :returns: a new local Opera driver
         """
         opera_driver = self.config.get('Driver', 'opera_driver_path')
-        self.logger.debug("Opera driver path given in properties: {0}".format(opera_driver))
+        self.logger.debug("Opera driver path given in properties: %s", opera_driver)
         return webdriver.Opera(executable_path=opera_driver, desired_capabilities=capabilities)
 
     def _setup_explorer(self, capabilities):
@@ -352,7 +349,7 @@ def _setup_explorer(self, capabilities):
         :returns: a new local Internet Explorer driver
         """
         explorer_driver = self.config.get('Driver', 'explorer_driver_path')
-        self.logger.debug("Explorer driver path given in properties: {0}".format(explorer_driver))
+        self.logger.debug("Explorer driver path given in properties: %s", explorer_driver)
         return webdriver.Ie(explorer_driver, capabilities=capabilities)
 
     def _setup_edge(self, capabilities):
@@ -362,7 +359,7 @@ def _setup_edge(self, capabilities):
         :returns: a new local Edge driver
         """
         edge_driver = self.config.get('Driver', 'edge_driver_path')
-        self.logger.debug("Edge driver path given in properties: {0}".format(edge_driver))
+        self.logger.debug("Edge driver path given in properties: %s", edge_driver)
         return webdriver.Edge(edge_driver, capabilities=capabilities)
 
     def _setup_phantomjs(self, capabilities):
@@ -372,7 +369,7 @@ def _setup_phantomjs(self, capabilities):
         :returns: a new local phantomjs driver
         """
         phantomjs_driver = self.config.get('Driver', 'phantomjs_driver_path')
-        self.logger.debug("Phantom driver path given in properties: {0}".format(phantomjs_driver))
+        self.logger.debug("Phantom driver path given in properties: %s", phantomjs_driver)
         return webdriver.PhantomJS(executable_path=phantomjs_driver, desired_capabilities=capabilities)
 
     def _setup_appium(self):

toolium/config_parser.py

@@ -18,8 +18,7 @@
 
 import logging
 
-# Python 2 and 3 compatibility
-from six.moves import configparser, StringIO
+from six.moves import configparser, StringIO  # Python 2 and 3 compatibility
 
 
 class ExtendedConfigParser(configparser.ConfigParser):
@@ -113,14 +112,14 @@ def get_config_from_file(conf_properties_files):
         for conf_properties_file in files_list:
             result = config.read(conf_properties_file)
             if len(result) == 0:
-                message = 'Properties config file not found: {}'.format(conf_properties_file)
+                message = 'Properties config file not found: %s'
                 if len(files_list) == 1:
-                    logger.error(message)
-                    raise Exception(message)
+                    logger.error(message, conf_properties_file)
+                    raise Exception(message % conf_properties_file)
                 else:
-                    logger.debug('Properties config file not found: {}'.format(conf_properties_file))
+                    logger.debug(message, conf_properties_file)
             else:
-                logger.debug('Reading properties from file: {}'.format(conf_properties_file))
+                logger.debug('Reading properties from file: %s', conf_properties_file)
                 found = True
         if not found:
             message = 'Any of the properties config files has been found'

toolium/driver_wrapper.py

@@ -259,7 +259,7 @@ def connect(self, maximize=True):
 
         # Log window size
         window_size = self.utils.get_window_size()
-        self.logger.debug('Window size: {} x {}'.format(window_size['width'], window_size['height']))
+        self.logger.debug('Window size: %s x %s', window_size['width'], window_size['height'])
 
         # Update baseline
         self.update_visual_baseline()

toolium/jira.py

@@ -130,10 +130,10 @@ def change_jira_status(test_key, test_status, test_comment, test_attachments):
     logger = logging.getLogger(__name__)
 
     if not execution_url:
-        logger.warn("Test Case '{}' can not be updated: execution_url is not configured".format(test_key))
+        logger.warning("Test Case '%s' can not be updated: execution_url is not configured", test_key)
         return
 
-    logger.info("Updating Test Case '{0}' in Jira with status {1}".format(test_key, test_status))
+    logger.info("Updating Test Case '%s' in Jira with status %s", test_key, test_status)
     composed_comments = comments
     if test_comment:
         composed_comments = '{}\n{}'.format(comments, test_comment) if comments else test_comment
@@ -150,14 +150,14 @@ def change_jira_status(test_key, test_status, test_comment, test_attachments):
             files = None
         response = requests.post(execution_url, data=payload, files=files)
     except Exception as e:
-        logger.warn("Error updating Test Case '{}': {}".format(test_key, e))
+        logger.warning("Error updating Test Case '%s': %s", test_key, e)
         return
 
     if response.status_code >= 400:
-        logger.warn("Error updating Test Case '{}': [{}] {}".format(test_key, response.status_code,
-                                                                    get_error_message(response.content)))
+        logger.warning("Error updating Test Case '%s': [%s] %s", test_key, response.status_code,
+                       get_error_message(response.content))
     else:
-        logger.debug("{}".format(response.content.decode().splitlines()[0]))
+        logger.debug("%s", response.content.decode().splitlines()[0])
 
 
 def get_error_message(response_content):

toolium/pageelements/page_element.py

@@ -70,10 +70,9 @@ def web_element(self):
             self._find_web_element()
         except NoSuchElementException as exception:
             parent_msg = " and parent locator '{}'".format(self.parent) if self.parent else ''
-            msg = "Page element of type '{}' with locator {}{} not found".format(type(self).__name__, self.locator,
-                                                                                 parent_msg)
-            self.logger.error(msg)
-            exception.msg += "\n  {}".format(msg)
+            msg = "Page element of type '%s' with locator %s%s not found"
+            self.logger.error(msg, type(self).__name__, self.locator, parent_msg)
+            exception.msg += "\n  {}".format(msg % (type(self).__name__, self.locator, parent_msg))
             raise exception
         return self._web_element
 
@@ -104,11 +103,10 @@ def wait_until_visible(self, timeout=10):
         try:
             self.utils.wait_until_element_visible(self, timeout)
         except TimeoutException as exception:
-            parent_msg = " and parent locator '{}'".format(self.parent, timeout) if self.parent else ''
-            msg = "Page element of type '{}' with locator {}{} not found or is not visible after {} seconds".format(
-                type(self).__name__, self.locator, parent_msg, timeout)
-            self.logger.error(msg)
-            exception.msg += "\n  {}".format(msg)
+            parent_msg = " and parent locator '{}'".format(self.parent) if self.parent else ''
+            msg = "Page element of type '%s' with locator %s%s not found or is not visible after %s seconds"
+            self.logger.error(msg, type(self).__name__, self.locator, parent_msg, timeout)
+            exception.msg += "\n  {}".format(msg % (type(self).__name__, self.locator, parent_msg, timeout))
             raise exception
         return self
 
@@ -121,11 +119,10 @@ def wait_until_not_visible(self, timeout=10):
         try:
             self.utils.wait_until_element_not_visible(self, timeout)
         except TimeoutException as exception:
-            parent_msg = " and parent locator '{}'".format(self.parent, timeout) if self.parent else ''
-            msg = "Page element of type '{}' with locator {}{} is still visible after {} seconds".format(
-                type(self).__name__, self.locator, parent_msg, timeout)
-            self.logger.error(msg)
-            exception.msg += "\n  {}".format(msg)
+            parent_msg = " and parent locator '{}'".format(self.parent) if self.parent else ''
+            msg = "Page element of type '%s' with locator %s%s is still visible after %s seconds"
+            self.logger.error(msg, type(self).__name__, self.locator, parent_msg, timeout)
+            exception.msg += "\n  {}".format(msg % (type(self).__name__, self.locator, parent_msg, timeout))
             raise exception
         return self
 

toolium/test/test_jira.py

@@ -79,9 +79,8 @@ def test_change_jira_status(logger):
                             'onlyIfStatusChanges=true']:
             assert partial_url in req_mock.request_history[0].text
 
-    # Check that binary response has been decoded
-    expected_response = "The Test Case Execution 'TOOLIUM-2' has been created"
-    logger.debug.assert_called_once_with(expected_response)
+    # Check logging call
+    logger.debug.assert_called_once_with("%s", "The Test Case Execution 'TOOLIUM-2' has been created")
 
 
 def test_change_jira_status_attachments(logger):
@@ -124,9 +123,8 @@ def test_change_jira_status_attachments(logger):
                         '"attachments1"; filename="ios_web.png"']:
         assert partial_url in body
 
-    # Check that binary response has been decoded
-    expected_response = "The Test Case Execution 'TOOLIUM-2' has been created"
-    logger.debug.assert_called_once_with(expected_response)
+    # Check logging call
+    logger.debug.assert_called_once_with("%s", "The Test Case Execution 'TOOLIUM-2' has been created")
 
 
 @mock.patch('toolium.jira.requests.get')
@@ -141,8 +139,8 @@ def test_change_jira_status_empty_url(jira_get, logger):
     jira.change_jira_status('TOOLIUM-1', 'Pass', None, [])
 
     # Check logging error message
-    expected_response = "Test Case 'TOOLIUM-1' can not be updated: execution_url is not configured"
-    logger.warn.assert_called_once_with(expected_response)
+    logger.warning.assert_called_once_with("Test Case '%s' can not be updated: execution_url is not configured",
+                                           'TOOLIUM-1')
 
 
 @mock.patch('toolium.jira.requests.post')
@@ -158,8 +156,7 @@ def test_change_jira_status_exception(jira_post, logger):
     jira.change_jira_status('TOOLIUM-1', 'Pass', None, [])
 
     # Check logging error message
-    expected_response = "Error updating Test Case 'TOOLIUM-1': exception error"
-    logger.warn.assert_called_once_with(expected_response)
+    logger.warning.assert_called_once_with("Error updating Test Case '%s': %s", 'TOOLIUM-1', jira_post.side_effect)
 
 
 def test_jira_annotation_pass(logger):

toolium/test/test_test_cases.py

@@ -68,17 +68,14 @@ def test_tear_down_pass(logger):
     assert test._test_passed is True
 
     # Check logging messages
-    init_message = 'Running new test: MockTestClass.mock_pass'
-    expected_response = "The test 'MockTestClass.mock_pass' has passed"
-    logger.info.assert_has_calls([mock.call(init_message), mock.call(expected_response)])
+    logger.info.assert_has_calls([mock.call('Running new test: %s', 'MockTestClass.mock_pass'),
+                                  mock.call("The test '%s' has passed", 'MockTestClass.mock_pass')])
 
 
 def test_tear_down_fail(logger):
     test = run_mock('mock_fail')
     assert test._test_passed is False
 
     # Check logging error messages
-    init_message = 'Running new test: MockTestClass.mock_fail'
-    expected_response = "The test 'MockTestClass.mock_fail' has failed: test error"
-    logger.info.assert_called_once_with(init_message)
-    logger.error.assert_called_once_with(expected_response)
+    logger.info.assert_called_once_with('Running new test: %s', 'MockTestClass.mock_fail')
+    logger.error.assert_called_once_with("The test '%s' has failed: %s", 'MockTestClass.mock_fail', 'test error')

toolium/test_cases.py

@@ -59,7 +59,7 @@ def setUp(self):
         # Get config and logger instances
         self.config = self.driver_wrapper.config
         self.logger = logging.getLogger(__name__)
-        self.logger.info("Running new test: {0}".format(self.get_subclassmethod_name()))
+        self.logger.info("Running new test: %s", self.get_subclassmethod_name())
 
     def tearDown(self):
         # Get unit test exception
@@ -79,11 +79,11 @@ def tearDown(self):
 
         if not exception:
             self._test_passed = True
-            self.logger.info("The test '{0}' has passed".format(self.get_subclassmethod_name()))
+            self.logger.info("The test '%s' has passed", self.get_subclassmethod_name())
         else:
             self._test_passed = False
             error_message = get_error_message_from_exception(exception)
-            self.logger.error("The test '{0}' has failed: {1}".format(self.get_subclassmethod_name(), error_message))
+            self.logger.error("The test '%s' has failed: %s", self.get_subclassmethod_name(), error_message)
 
 
 class SeleniumTestCase(BasicTestCase):