Merge lp:~gz/juju-ci-tools/utility_logged_exception into lp:juju-ci-tools

[Martin Packman]

Add logged_exception helper to utility factored out from deploy_stack

Pulls the LoggedException code from deploy_stack to a more reusable location.

There is one relevent functional change here, the call site in BoostrapManager.runtime_context now does not wrap SystemExit or KeyboardInterrupt. This feels correct to me, but I am perhaps missing something. We may want specific KeyboardInterrupt handling given SIGINT is our top level timeout method.

Not done in this branch, switching deploy_stack to using a named logger rather than logging directly, and using the new functions in other tests.

[lp:~gz/juju-ci-tools/utility_logged_exception]

1737. By Martin Packman on 2016-11-17

Also wrap KeyboardInterrupt as SIGINT is used for timeout

[Aaron Bentley (abentley)]

Thanks.

review: Approve

=== modified file 'deploy_stack.py'
--- deploy_stack.py	2016-11-14 22:18:53 +0000
+++ deploy_stack.py	2016-11-17 18:55:17 +0000
@@ -65,6 +65,7 @@
     configure_logging,
     ensure_deleted,
     ensure_dir,
+    logged_exception,
     LoggedException,
     PortTimeoutError,
     print_now,
@@ -753,16 +754,6 @@
         self.controller_strategy.tear_down()
         self.has_controller = False
 
-    def _log_and_wrap_exception(self, exc):
-        logging.exception(exc)
-        stdout = getattr(exc, 'output', None)
-        stderr = getattr(exc, 'stderr', None)
-        if stdout or stderr:
-            logging.info(
-                'Output from exception:\nstdout:\n%s\nstderr:\n%s',
-                stdout, stderr)
-        return LoggedException(exc)
-
     @contextmanager
     def bootstrap_context(self, machines, omit_config=None):
         """Context for bootstrapping a state server."""
@@ -845,13 +836,11 @@
         Tear down.  (self.keep_env is ignored.)
         """
         try:
-            try:
-                yield
             # If an exception is raised that indicates an error, log it
             # before tearing down so that the error is closely tied to
             # the failed operation.
-            except Exception as e:
-                raise self._log_and_wrap_exception(e)
+            with logged_exception(logging):
+                yield
         except:
             # If run from a windows machine may not have ssh to get
             # logs
@@ -873,18 +862,13 @@
         control is yielded.
         """
         try:
-            try:
+            with logged_exception(logging):
                 if len(self.known_hosts) == 0:
                     self.known_hosts.update(
                         self.controller_strategy.get_hosts())
                 if addable_machines is not None:
                     self.client.add_ssh_machines(addable_machines)
                 yield
-            # avoid logging GeneratorExit
-            except GeneratorExit:
-                raise
-            except BaseException as e:
-                raise self._log_and_wrap_exception(e)
         except:
             if self.has_controller:
                 safe_print_status(self.client)

=== modified file 'tests/test_utility.py'
--- tests/test_utility.py	2016-11-08 15:17:26 +0000
+++ tests/test_utility.py	2016-11-17 18:55:17 +0000
@@ -18,6 +18,7 @@
 
 from mock import (
     call,
+    Mock,
     patch,
     )
 
@@ -35,6 +36,9 @@
     get_deb_arch,
     get_winrm_certs,
     is_ipv6_address,
+    log_and_wrap_exception,
+    logged_exception,
+    LoggedException,
     quote,
     run_command,
     scoped_environ,
@@ -714,3 +718,48 @@
             qualified_model_name('admin/default', 'admin'),
             'admin/default'
         )
+
+
+class TestLoggedException(TestCase):
+
+    def test_no_error_no_log(self):
+        mock_logger = Mock(spec_set=[])
+        with logged_exception(mock_logger):
+            pass
+
+    def test_exception_logged_and_wrapped(self):
+        mock_logger = Mock(spec=['exception'])
+        err = Exception('some error')
+        with self.assertRaises(LoggedException) as ctx:
+            with logged_exception(mock_logger):
+                raise err
+        self.assertIs(ctx.exception.exception, err)
+        mock_logger.exception.assert_called_once_with(err)
+
+    def test_generator_exit_not_wrapped(self):
+        mock_logger = Mock(spec_set=[])
+        with self.assertRaises(GeneratorExit):
+            with logged_exception(mock_logger):
+                raise GeneratorExit
+
+    def test_keyboard_interrupt_wrapped(self):
+        mock_logger = Mock(spec=['exception'])
+        err = KeyboardInterrupt()
+        with self.assertRaises(LoggedException) as ctx:
+            with logged_exception(mock_logger):
+                raise err
+        self.assertIs(ctx.exception.exception, err)
+        mock_logger.exception.assert_called_once_with(err)
+
+    def test_output_logged(self):
+        mock_logger = Mock(spec=['exception', 'info'])
+        err = Exception('some error')
+        err.output = 'some output'
+        with self.assertRaises(LoggedException) as ctx:
+            with logged_exception(mock_logger):
+                raise err
+        self.assertIs(ctx.exception.exception, err)
+        mock_logger.exception.assert_called_once_with(err)
+        mock_logger.info.assert_called_once_with(
+            'Output from exception:\nstdout:\n%s\nstderr:\n%s', 'some output',
+            None)

=== modified file 'utility.py'
--- utility.py	2016-11-16 20:28:18 +0000
+++ utility.py	2016-11-17 18:55:17 +0000
@@ -526,3 +526,31 @@
 def get_unit_ipaddress(client, unit_name):
     status = client.get_status()
     return status.get_unit(unit_name)['public-address']
+
+
+def log_and_wrap_exception(logger, exc):
+    """"Record exc details to logger and return wrapped in LoggedException."""
+    logger.exception(exc)
+    stdout = getattr(exc, 'output', None)
+    stderr = getattr(exc, 'stderr', None)
+    if stdout or stderr:
+        logger.info(
+            'Output from exception:\nstdout:\n%s\nstderr:\n%s',
+            stdout, stderr)
+    return LoggedException(exc)
+
+
+@contextmanager
+def logged_exception(logger):
+    """
+    Record exceptions in managed context to logger and reraise LoggedException.
+
+    Note that BaseException classes like SystemExit, KeyboardInterrupt, and
+    GeneratorExit are not wrapped.
+    """
+    try:
+        yield
+    except LoggedException:
+        raise
+    except (Exception, KeyboardInterrupt) as e:
+        raise log_and_wrap_exception(logger, e)