Merge lp:~elopio/u1-test-utils/logger_decorator into lp:u1-test-utils

[Leo Arias]

Added the actions logger decorator for the page objects.

[lp:~elopio/u1-test-utils/logger_decorator]

48. By Leo Arias on 2013-04-09

Added the decorator to the SSO pages.

[Natalia Bidart (nataliabidart)]

Looks good. About the decorator, instead of

11 + def log_and_call(*args, **kwargs):
12 + class_name = str(args[0].__class__.__name__)

I would suggest using this approach, which is more explicit:

11 + def log_and_call(instance, *args, **kwargs):
12 + class_name = str(instance.__class__.__name__)
...
25 + return method(instance, *args, **kwargs)

Futhermore, I would suggest adding a decorator that will receive the logging function as a param, thus allowing the caller to log using different levels. For example:

http://bazaar.launchpad.net/~pycassos/pycasa/trunk/view/head:/pycasa/utils.py#L120

Nitpicking detail: there should be an empty blank line between the import <module> block and the from <module> import <feature> block.

review: Needs Fixing

[lp:~elopio/u1-test-utils/logger_decorator]

49. By Leo Arias on 2013-04-10

Improved the logger using a more explicit approach with the instance as parameter.

50. By Leo Arias on 2013-04-11

Improve the logger decorator to receive the logging funciton.

51. By Leo Arias on 2013-04-11

Removed the log_func default.

52. By Leo Arias on 2013-04-11

Remove the unnecessary test.

53. By Leo Arias on 2013-04-11

Fixed lint.

[Natalia Bidart (nataliabidart)]

I made some tweaks to this logging function and pasted them here:

https://pastebin.canonical.com/89011/

I added comments inline explaining the changes, but will duplicate those here for the sake of the review:

"Creating several strings depending on conditions is expensive.
Also, is better to have non-chaging log messages to be able to
grep for specific keywords when debugging, so, I prefer to always
log the args and kwargs even if they are not set, since the fact
that no args nor kwargs were given is an important info to log.
Is particularly important to use %r and not %s.

You should not format the string to log outside the logging
function, for mainly 2 reasons: the formatting may not be needed
since the currently set log level may be higher than the level of
log_func, and because there may be a formatting error that could
raise an exception making the whole call to 'f' fail (and we want
to avoid that)."

review: Needs Fixing

[lp:~elopio/u1-test-utils/logger_decorator]

54. By Leo Arias on 2013-04-12

Implemented nessita's suggestion for the log line.

55. By Leo Arias on 2013-04-12

Empty line between import forms.

[Natalia Bidart (nataliabidart)]

Looks great! Thanks a lot.

review: Approve

=== modified file 'u1testutils/sst/__init__.py'
--- u1testutils/sst/__init__.py	2013-04-10 19:25:21 +0000
+++ u1testutils/sst/__init__.py	2013-04-12 15:18:27 +0000
@@ -18,10 +18,34 @@
 
 import sst.actions
 
+from functools import wraps
+
 
 logger = logging.getLogger('User test')
 
 
+def log_action(log_func):
+    """Decorator to log the call of an action method."""
+
+    def middle(f):
+
+        @wraps(f)
+        def inner(instance, *args, **kwargs):
+            class_name = str(instance.__class__.__name__)
+            docstring = f.__doc__
+            if docstring:
+                docstring = docstring.split('\n')[0].strip()
+            else:
+                docstring = f.__name__
+            log_line = '%r: %r. Arguments %r. Keyword arguments: %r.'
+            log_func(log_line, class_name, docstring, args, kwargs)
+            return f(instance, *args, **kwargs)
+
+        return inner
+
+    return middle
+
+
 class Page(object):
     """Base class for the page objects used in acceptance testing.
 

=== modified file 'u1testutils/sst/selftests/unit/test_pages.py'
--- u1testutils/sst/selftests/unit/test_pages.py	2013-04-08 18:43:37 +0000
+++ u1testutils/sst/selftests/unit/test_pages.py	2013-04-12 15:18:27 +0000
@@ -12,10 +12,13 @@
 # You should have received a copy of the GNU General Public License along
 # with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import logging
 import mock
 import testtools
 
-from u1testutils.sst import Page
+import u1testutils.logging
+
+from u1testutils.sst import log_action, Page
 
 
 class PageTestCase(testtools.TestCase):
@@ -58,3 +61,59 @@
             page.headings2 = []
             page.assert_page_is_open()
             assert not mock_assert.called
+
+
+class PageWithLogDecorator(Page):
+
+    @log_action(logging.info)
+    def do_something_without_docstring(self, *args, **kwargs):
+        pass
+
+    @log_action(logging.info)
+    def do_something_with_docstring(self, *args, **kwargs):
+        """Do something with docstring."""
+        pass
+
+    @log_action(logging.info)
+    def do_something_with_multiline_docstring(self, *args, **kwargs):
+        """Do something with a multiline docstring.
+
+        This should not be logged.
+        """
+        pass
+
+
+class PageLoggingTestCase(u1testutils.logging.LogHandlerTestCase):
+
+    def setUp(self):
+        super(PageLoggingTestCase, self).setUp()
+        self.root_logger.setLevel(logging.INFO)
+        self.page = PageWithLogDecorator(check=False)
+
+    def test_logged_action_without_docstring(self):
+        self.page.do_something_without_docstring(
+            'arg1', 'arg2', arg3='arg3', arg4='arg4')
+        self.assertLogLevelContains(
+            'INFO',
+            "'PageWithLogDecorator': 'do_something_without_docstring'. "
+            "Arguments ('arg1', 'arg2'). "
+            "Keyword arguments: {'arg3': 'arg3', 'arg4': 'arg4'}.")
+
+    def test_logged_action_with_docstring(self):
+        self.page.do_something_with_docstring(
+            'arg1', 'arg2', arg3='arg3', arg4='arg4')
+        self.assertLogLevelContains(
+            'INFO',
+            "'PageWithLogDecorator': 'Do something with docstring.'. "
+            "Arguments ('arg1', 'arg2'). "
+            "Keyword arguments: {'arg3': 'arg3', 'arg4': 'arg4'}.")
+
+    def test_logged_action_with_multiline_docstring(self):
+        self.page.do_something_with_multiline_docstring(
+            'arg1', 'arg2', arg3='arg3', arg4='arg4')
+        self.assertLogLevelContains(
+            'INFO',
+            "'PageWithLogDecorator': "
+            "'Do something with a multiline docstring.'. "
+            "Arguments ('arg1', 'arg2'). "
+            "Keyword arguments: {'arg3': 'arg3', 'arg4': 'arg4'}.")

=== modified file 'u1testutils/sst/sso/pages.py'
--- u1testutils/sst/sso/pages.py	2013-04-10 19:47:20 +0000
+++ u1testutils/sst/sso/pages.py	2013-04-12 15:18:27 +0000
@@ -12,10 +12,14 @@
 # You should have received a copy of the GNU General Public License along
 # with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import logging
+
 import sst.actions
 
 import u1testutils.sst
 
+from u1testutils.sst import log_action
+
 
 class LogIn(u1testutils.sst.Page):
     """Log in page of the Ubuntu Single Sign On website.
@@ -39,6 +43,7 @@
         sst.actions.assert_element(tag='h1', text='Ubuntu Single Sign On')
         sst.actions.assert_element(tag='h2', text='Are you new?')
 
+    @log_action(logging.info)
     def log_in_to_site_recognized(self, user=None):
         """Fill the log in form and continue to the site that requested it.
 
@@ -51,6 +56,7 @@
         """
         self._log_in(user)
 
+    @log_action(logging.info)
     def log_in_to_site_not_recognized(self, user=None):
         """Fill the log in form and continue to the next step.
 
@@ -87,6 +93,7 @@
             css_class='btn', name='continue')
         sst.actions.click_button(continue_button)
 
+    @log_action(logging.info)
     def go_to_create_new_account(self):
         """Go to the Create new account page."""
         new_account_link = sst.actions.get_element(id='new-account-link')
@@ -109,6 +116,7 @@
     title = 'Create account'
     url_path = '/\+new_account'
 
+    @log_action(logging.info)
     def create_ubuntu_sso_account(self, user):
         """Fill the new account form and continue to the next step.
 
@@ -147,6 +155,7 @@
     title = 'Registration mail sent'
     url_path = '/\+new_account'
 
+    @log_action(logging.info)
     def confirm_email_to_site_recognized(self, confirmation_code):
         """Confirm email and continue to the site that requested the log in.
 
@@ -157,6 +166,7 @@
         """
         self._confirm_email(confirmation_code)
 
+    @log_action(logging.info)
     def confirm_email_to_site_not_recognized(self, confirmation_code):
         """Enter the confirmation code and continue to the next step.
 
@@ -215,10 +225,12 @@
         cancel_link = sst.actions.get_element(tag='a', text='cancel')
         sst.actions.click_link(cancel_link)
 
+    @log_action(logging.info)
     def confirm(self):
         self._click_continue_button()
         return YourAccount(self.user_name)
 
+    @log_action(logging.info)
     def cancel(self):
         return YourAccount(self.user_name)
 
@@ -249,6 +261,7 @@
         """
         sst.actions.assert_title_contains(self.title, regex=True)
 
+    @log_action(logging.info)
     def make_all_information_available_to_website(self):
         """Select all the user available information.
 
@@ -265,6 +278,7 @@
             'form[name="decideform"] > .info-items > .list > li > '
             'input[type="checkbox"]')
 
+    @log_action(logging.info)
     def yes_sign_me_in(self):
         """Accept to sign in to the site not recognized and go back to it."""
         sign_me_in_button = sst.actions.get_element(css_class='btn',
@@ -299,6 +313,7 @@
 
 class _UserSubHeader(object):
 
+    @log_action(logging.info)
     def log_out(self):
         """Log out from the web site."""
         sst.actions.click_link('logout-link')