Merge lp:~frankban/charms/precise/juju-gui/bug-1132905-log-hook into lp:~juju-gui/charms/precise/juju-gui/trunk

[Francesco Banconi]

Add and use a log_hook context manager.

Replace the current calls to log_entry and log_exit in the __main__ of
the hooks with a log_hook context manager, simplifying the code a bit.

Avoiding log_entry and log_exit also temporarily works around a problem
they have with the juju-core handling of strings starting with "--" in
juju-log.

https://codereview.appspot.com/7379050/

[Francesco Banconi (frankban)]

Reviewers: mp+150413_code.launchpad.net,

Message:
Please take a look.

Description:
Add and use a log_hook context manager.

Replace the current calls to log_entry and log_exit in the __main__ of
the hooks with a log_hook context manager, simplifying the code a bit.

Avoiding log_entry and log_exit also temporarily works around a problem
they have with the juju-core handling of strings starting with "--" in
juju-log.

https://code.launchpad.net/~frankban/charms/precise/juju-gui/bug-1132905-log-hook/+merge/150413

(do not edit description out of merge proposal)

Please review this at https://codereview.appspot.com/7379050/

Affected files:
   A [revision details]
   M hooks/config-changed
   M hooks/install
   M hooks/start
   M hooks/stop
   M hooks/utils.py
   M tests/test_utils.py

[Gary Poster (gary)]

LGTM.

Nice tests.

Thanks!

https://codereview.appspot.com/7379050/diff/1/hooks/config-changed
File hooks/config-changed (right):

https://codereview.appspot.com/7379050/diff/1/hooks/config-changed#newcode135
hooks/config-changed:135: with log_hook():
Nice!

https://codereview.appspot.com/7379050/

[Francesco Banconi (frankban)]

*** Submitted:

Add and use a log_hook context manager.

Replace the current calls to log_entry and log_exit in the __main__ of
the hooks with a log_hook context manager, simplifying the code a bit.

Avoiding log_entry and log_exit also temporarily works around a problem
they have with the juju-core handling of strings starting with "--" in
juju-log.

R=gary.poster
CC=
https://codereview.appspot.com/7379050

https://codereview.appspot.com/7379050/

=== modified file 'hooks/config-changed'
--- hooks/config-changed	2013-02-04 18:05:31 +0000
+++ hooks/config-changed	2013-02-25 19:12:24 +0000
@@ -4,14 +4,11 @@
 # Copyright 2012 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
-from subprocess import CalledProcessError
 import sys
 
 from charmhelpers import (
     get_config,
     log,
-    log_entry,
-    log_exit,
     service_control,
     STOP,
 )
@@ -27,6 +24,7 @@
     fetch_gui,
     HAPROXY,
     IMPROV,
+    log_hook,
     NGINX,
     save_or_create_certificates,
     setup_gui,
@@ -134,12 +132,5 @@
 
 
 if __name__ == '__main__':
-    log_entry()
-    try:
+    with log_hook():
         main()
-    except CalledProcessError as e:
-        log('Exception caught:')
-        log(e.output)
-        raise
-    finally:
-        log_exit()

=== modified file 'hooks/install'
--- hooks/install	2013-02-06 08:46:56 +0000
+++ hooks/install	2013-02-25 19:12:24 +0000
@@ -3,10 +3,8 @@
 
 import os
 import shutil
-from subprocess import (
-    CalledProcessError,
-    check_call,
-)
+from subprocess import check_call
+
 
 # If the user's environment has "juju-origin: ppa" set, they will
 # automatically have access to python-charmhelpers and python-shelltoolbox.
@@ -30,8 +28,6 @@
 from charmhelpers import (
     get_config,
     log,
-    log_entry,
-    log_exit,
 )
 from shelltoolbox import (
     apt_get_install,
@@ -43,6 +39,7 @@
     config_json,
     fetch_api,
     fetch_gui,
+    log_hook,
     save_or_create_certificates,
     setup_gui,
     setup_nginx,
@@ -88,12 +85,5 @@
 
 
 if __name__ == '__main__':
-    log_entry()
-    try:
+    with log_hook():
         main()
-    except CalledProcessError as e:
-        log('Exception caught:')
-        log(e.output)
-        raise
-    finally:
-        log_exit()

=== modified file 'hooks/start'
--- hooks/start	2013-02-04 18:05:31 +0000
+++ hooks/start	2013-02-25 19:12:24 +0000
@@ -4,12 +4,11 @@
 from charmhelpers import (
     get_config,
     log,
-    log_entry,
-    log_exit,
     open_port,
 )
 
 from utils import (
+    log_hook,
     start_agent,
     start_gui,
     start_improv,
@@ -38,8 +37,5 @@
 
 
 if __name__ == '__main__':
-    log_entry()
-    try:
+    with log_hook():
         main()
-    finally:
-        log_exit()

=== modified file 'hooks/stop'
--- hooks/stop	2012-12-19 09:57:45 +0000
+++ hooks/stop	2013-02-25 19:12:24 +0000
@@ -1,14 +1,13 @@
 #!/usr/bin/env python2
 #-*- python -*-
 
-from charmhelpers import (
-    get_config,
-    log_entry,
-    log_exit,
+from charmhelpers import get_config
+
+from utils import (
+    log_hook,
+    stop,
 )
 
-from utils import stop
-
 
 def main():
     config = get_config()
@@ -16,8 +15,5 @@
 
 
 if __name__ == '__main__':
-    log_entry()
-    try:
+    with log_hook():
         main()
-    finally:
-        log_exit()

=== modified file 'hooks/utils.py'
--- hooks/utils.py	2013-02-05 18:02:27 +0000
+++ hooks/utils.py	2013-02-25 19:12:24 +0000
@@ -17,6 +17,7 @@
     'JUJU_GUI_DIR',
     'JUJU_GUI_SITE',
     'JUJU_PEM',
+    'log_hook',
     'NGINX',
     'parse_source',
     'render_to_file',
@@ -30,10 +31,12 @@
     'WEB_PORT',
 ]
 
+from contextlib import contextmanager
 import json
 import os
 import logging
 import shutil
+from subprocess import CalledProcessError
 import tempfile
 import tempita
 
@@ -42,6 +45,7 @@
     command,
     environ,
     run,
+    script_name,
     search_file,
     Serializer,
     su,
@@ -132,6 +136,25 @@
     return line.split('=')[1].strip('"')
 
 
+@contextmanager
+def log_hook():
+    """Log when an hook starts and stops its execution.
+
+    Also log to stdout possible CalledProcessError exceptions raised executing
+    the hook.
+    """
+    script = script_name()
+    log(">>> Entering {}".format(script))
+    try:
+        yield
+    except CalledProcessError as err:
+        log('Exception caught:')
+        log(err.output)
+        raise
+    finally:
+        log("<<< Exiting {}".format(script))
+
+
 def parse_source(source):
     """Parse the ``juju-gui-source`` option.
 

=== modified file 'tests/test_utils.py'
--- tests/test_utils.py	2013-02-05 17:52:22 +0000
+++ tests/test_utils.py	2013-02-25 19:12:24 +0000
@@ -4,11 +4,13 @@
 import os
 import shutil
 from simplejson import dumps
+from subprocess import CalledProcessError
 import tempfile
 import tempita
 import unittest
 
 import charmhelpers
+
 from utils import (
     _get_by_attr,
     API_PORT,
@@ -18,6 +20,7 @@
     get_zookeeper_address,
     JUJU_GUI_DIR,
     JUJU_PEM,
+    log_hook,
     parse_source,
     render_to_file,
     save_or_create_certificates,
@@ -266,6 +269,49 @@
         self.assertEqual(self.zookeeper_address, address)
 
 
+class LogHookTest(unittest.TestCase):
+
+    def setUp(self):
+        # Monkeypatch the charmhelpers log function.
+        self.output = []
+        self.original = utils.log
+        utils.log = self.output.append
+
+    def tearDown(self):
+        # Restore the original charmhelpers log function.
+        utils.log = self.original
+
+    def test_logging(self):
+        # The function emits log messages on entering and exiting the hook.
+        with log_hook():
+            self.output.append('executing hook')
+        self.assertEqual(3, len(self.output))
+        enter_message, executing_message, exit_message = self.output
+        self.assertIn('>>> Entering', enter_message)
+        self.assertEqual('executing hook', executing_message)
+        self.assertIn('<<< Exiting', exit_message)
+
+    def test_subprocess_error(self):
+        # If a CalledProcessError exception is raised, the command output is
+        # logged.
+        with self.assertRaises(CalledProcessError) as cm:
+            with log_hook():
+                raise CalledProcessError(2, 'command', 'output')
+        exception = cm.exception
+        self.assertIsInstance(exception, CalledProcessError)
+        self.assertEqual(2, exception.returncode)
+        self.assertEqual('output', self.output[-2])
+
+    def test_error(self):
+        # Possible errors are re-raised by the context manager.
+        with self.assertRaises(TypeError) as cm:
+            with log_hook():
+                raise TypeError
+        exception = cm.exception
+        self.assertIsInstance(exception, TypeError)
+        self.assertIn('<<< Exiting', self.output[-1])
+
+
 class ParseSourceTest(unittest.TestCase):
 
     def test_latest_stable_release(self):