Added helper decorator to log method arguments

The decorator originates from Neutron [1]. It's used there to log
arguments for oslo.messaging cast()/call() methods useful when debugging
interactions between different services.

The original version of the decorator was extended to work correctly for
class methods. Static methods are out of scope for this particular
decorator.

The original name of the decorator was also changed (log ->
log_method_call) to reflect the fact that it's designed for methods
only, not to be used as a general logger helper for any callable. If one
is needed, we need to introduce another generic decorator for all
callables that won't distinguish between first argument and the rest.

The plan is to merge the decorator into oslo.log and then adopt it in
oslo.messaging itself to make logging facility not specific to Neutron.

Added a simplistic unit test to check that decorator works as expected
for both object and class methods.

[1]: http://git.openstack.org/cgit/openstack/neutron/tree/neutron/common/log.py

Change-Id: I8436c954076fdc42482dec8e88f3075f055d425e

oslo/log/helpers.py

@@ -0,0 +1,47 @@
+# Copyright (C) 2013 eNovance SAS <licensing@enovance.com>
+#
+# Licensed under the Apache License, Version 2.0 (the "License"); you may
+# not use this file except in compliance with the License. You may obtain
+# a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+# License for the specific language governing permissions and limitations
+# under the License.
+
+"""Log helper functions."""
+
+import functools
+import logging
+
+
+def _get_full_class_name(cls):
+    return '%s.%s' % (cls.__module__,
+                      getattr(cls, '__qualname__', cls.__name__))
+
+
+def log_method_call(method):
+    """Decorator helping to log method calls.
+
+    The decorator is not intended to be used for static methods (which
+    are just simple functions from Python point of view).
+
+    :param method: Method to decorate to be logged.
+    :type method: method definition
+    """
+    log = logging.getLogger(method.__module__)
+
+    @functools.wraps(method)
+    def wrapper(*args, **kwargs):
+        first_arg = args[0]
+        cls = first_arg if isinstance(first_arg, type) else first_arg.__class__
+        data = {'class_name': _get_full_class_name(cls),
+                'method_name': method.__name__,
+                'args': args[1:], 'kwargs': kwargs}
+        log.debug('%(class_name)s method %(method_name)s '
+                  'called with arguments %(args)s %(kwargs)s', data)
+        return method(*args, **kwargs)
+    return wrapper

tests/unit/test_helpers.py

@@ -0,0 +1,46 @@
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+import mock
+from oslo.log import helpers
+from oslotest import base as test_base
+
+
+class LogHelpersTestCase(test_base.BaseTestCase):
+
+    def test_log_decorator(self):
+        '''Test that LOG.debug is called with proper arguments.'''
+
+        class test_class(object):
+            @helpers.log_method_call
+            def test_method(self, arg1, arg2, arg3, *args, **kwargs):
+                pass
+
+            @classmethod
+            @helpers.log_method_call
+            def test_classmethod(cls, arg1, arg2, arg3, *args, **kwargs):
+                pass
+
+        args = tuple(range(6))
+        kwargs = {'kwarg1': 6, 'kwarg2': 7}
+
+        obj = test_class()
+        for method_name in ('test_method', 'test_classmethod'):
+            data = {'class_name': helpers._get_full_class_name(test_class),
+                    'method_name': method_name,
+                    'args': args,
+                    'kwargs': kwargs}
+
+            method = getattr(obj, method_name)
+            with mock.patch('logging.Logger.debug') as debug:
+                method(*args, **kwargs)
+                debug.assert_called_with(mock.ANY, data)