Enable logging just exception types to reduce clutter in known cases

Author: Milan Falešník

src/widgetastic/browser.py

@@ -278,7 +278,7 @@ def perform_click(self):
         """Clicks the left mouse button at the current mouse position."""
         ActionChains(self.selenium).click().perform()
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     def click(self, locator, *args, **kwargs):
         """Clicks at a specific element using two separate events (mouse move, mouse click).
 
@@ -299,7 +299,7 @@ def click(self, locator, *args, **kwargs):
         except (StaleElementReferenceException, UnexpectedAlertPresentException):
             pass
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     def raw_click(self, locator, *args, **kwargs):
         """Clicks at a specific element using the direct event.
 
@@ -347,7 +347,7 @@ def is_displayed(self, locator, *args, **kwargs):
         # Just in case
         return False
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     @repeat_once_on_exceptions(
         StaleElementReferenceException, MoveTargetOutOfBoundsException,
         check_safe=True)
@@ -392,7 +392,7 @@ def move_to_element(self, locator, *args, **kwargs):
                         locator))
         return el
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     def move_by_offset(self, x, y):
         """Moves mouse pointer by given values."""
         ActionChains(self.selenium).move_by_offset(x, y).perform()
@@ -404,7 +404,8 @@ def execute_script(self, script, *args, **kwargs):
             self.logger.debug('execute_script(%r)', script)
         return self.selenium.execute_script(dedent(script), *args, **kwargs)
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def classes(self, locator, *args, **kwargs):
         """Return a list of classes attached to the element.
 
@@ -416,7 +417,8 @@ def classes(self, locator, *args, **kwargs):
         return set(self.execute_script(
             "return arguments[0].classList;", self.element(locator, *args, **kwargs), silent=True))
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def tag(self, *args, **kwargs):
         """Returns the tag name of the element represented by the locator passed.
 
@@ -427,7 +429,8 @@ def tag(self, *args, **kwargs):
         """
         return self.element(*args, **kwargs).tag_name
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def text(self, locator, *args, **kwargs):
         """Returns the text inside the element represented by the locator passed.
 
@@ -455,24 +458,26 @@ def text(self, locator, *args, **kwargs):
 
         return normalize_space(text)
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def get_attribute(self, attr, locator, *args, **kwargs):
         """Get attribute value from an element."""
         return self.element(locator, *args, **kwargs).get_attribute(attr)
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     def set_attribute(self, attr, value, locator, *args, **kwargs):
         return self.execute_script(
             "arguments[0].setAttribute(arguments[1], arguments[2]);",
             self.element(locator, *args, **kwargs), attr, value)
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def size_of(self, locator, *args, **kwargs):
         """Returns element's size as a tuple of width/height."""
         size = self.element(locator, *args, **kwargs).size
         return Size(size['width'], size['height'])
 
-    @logged(log_args=True, only_after=True, debug_only=True)
+    @logged(log_args=True, only_after=True, debug_only=True, log_full_exception=False)
     def clear(self, locator, *args, **kwargs):
         """Clears a text input with given locator."""
         el = self.element(locator, *args, **kwargs)
@@ -482,11 +487,12 @@ def clear(self, locator, *args, **kwargs):
         self.plugin.ensure_page_safe()
         return result
 
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def is_selected(self, locator, *args, **kwargs):
         return self.element(locator, *args, **kwargs).is_selected()
 
-    @logged(log_args=True, debug_only=True)
+    @logged(log_args=True, debug_only=True, log_full_exception=False)
     def send_keys(self, text, locator, *args, **kwargs):
         """Sends keys to the element. Detects the file inputs automatically.
 
@@ -539,7 +545,8 @@ def get_alert(self):
         return self.selenium.switch_to_alert()
 
     @property
-    @logged(log_args=True, log_result=True, only_after=True, debug_only=True)
+    @logged(
+        log_args=True, log_result=True, only_after=True, debug_only=True, log_full_exception=False)
     def alert_present(self):
         """Checks whether there is any alert present.
 
@@ -554,7 +561,7 @@ def alert_present(self):
         else:
             return True
 
-    @logged(log_args=True)
+    @logged(log_args=True, log_full_exception=False)
     def dismiss_any_alerts(self):
         """Loops until there are no further alerts present to dismiss.
 
@@ -568,7 +575,7 @@ def dismiss_any_alerts(self):
         except NoAlertPresentException:  # Just in case. alert_present should be reliable
             pass
 
-    @logged(log_args=True, log_result=True)
+    @logged(log_args=True, log_result=True, log_full_exception=False)
     def handle_alert(self, cancel=False, wait=30.0, squash=False, prompt=None, check_present=False):
         """Handles an alert popup.
 

src/widgetastic/log.py

@@ -50,7 +50,9 @@ def create_widget_logger(widget_path, logger=None):
         {'widget_path': widget_path})
 
 
-def logged(log_args=False, log_result=False, only_after=False, debug_only=False):
+def logged(
+        log_args=False, log_result=False, only_after=False, debug_only=False,
+        log_full_exception=True):
     """Decorator that logs entry and exit to a method and also times the execution.
 
     It assumes that the object where you decorate the methods on has a ``.logger`` attribute.
@@ -65,6 +67,7 @@ def logged(log_args=False, log_result=False, only_after=False, debug_only=False)
         log_result: Whether to log the result value returned from the method.
         only_after: Whether to log only after the method finished.
         debug_only: Use only debug log level at max.
+        log_full_exception: Whether to log the full exceptions.
     """
     def g(f):
         @wraps(f)
@@ -85,11 +88,16 @@ def wrapped(self, *args, **kwargs):
                     '%s not read on widget\'s request (elapsed %.0f ms)',
                     signature, elapsed_time)
                 raise
-            except Exception:
+            except Exception as e:
                 elapsed_time = (time.time() - start_time) * 1000.0
-                self.logger.exception(
-                    'An exception happened during %s call (elapsed %.0f ms)',
-                    signature, elapsed_time)
+                if log_full_exception:
+                    self.logger.exception(
+                        'An exception happened during %s call (elapsed %.0f ms)',
+                        signature, elapsed_time)
+                else:
+                    self.logger.error(
+                        'An exception %s happened during %s call (elapsed %.0f ms)',
+                        str(e), signature, elapsed_time)
                 raise
             else:
                 elapsed_time = (time.time() - start_time) * 1000.0