Use method's logger in log decorator

Previously decorators shared logger. This patch makes LOG object in
closure for every decorated method in order to use correct logging
level.

Closes-Bug: #1340778
Change-Id: If907acbab34f8bf23e1277e66c3ddd839f668764

diff --git a/neutron/common/log.py b/neutron/common/log.py
index 85e4dce80d777508ab602de5aba6a559a0529794..405b54a9109c6a17e0aa124ac9bc4ef52cf6a471 100644 (file)
--- a/neutron/common/log.py
+++ b/neutron/common/log.py
@@ -15,21 +15,23 @@
 # under the License.
 
 """Log helper functions."""
+import functools
 
 from neutron.openstack.common import log as logging
 
-LOG = logging.getLogger(__name__)
-
 
 def log(method):
     """Decorator helping to log method calls."""
+    LOG = logging.getLogger(method.__module__)
+
+    @functools.wraps(method)
     def wrapper(*args, **kwargs):
         instance = args[0]
-        data = {"class_name": (instance.__class__.__module__ + '.'
-                               + instance.__class__.__name__),
+        data = {"class_name": "%s.%s" % (instance.__class__.__module__,
+                                         instance.__class__.__name__),
                 "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)
+        LOG.debug('%(class_name)s method %(method_name)s'
+                  ' called with arguments %(args)s %(kwargs)s', data)
         return method(*args, **kwargs)
     return wrapper

diff --git a/neutron/tests/unit/test_common_log.py b/neutron/tests/unit/test_common_log.py
index 318613a1b5b25fc5bbff764527fb89062613a0e1..ed396ce7390fe98e75c51373be6dc3ff5f0eff2a 100644 (file)
--- a/neutron/tests/unit/test_common_log.py
+++ b/neutron/tests/unit/test_common_log.py
@@ -18,9 +18,6 @@ from neutron.common import log as call_log
 from neutron.tests import base
 
 
-MODULE_NAME = 'neutron.tests.unit.test_common_log'
-
-
 class TargetKlass(object):
 
     @call_log.log
@@ -32,39 +29,29 @@ class TestCallLog(base.BaseTestCase):
     def setUp(self):
         super(TestCallLog, self).setUp()
         self.klass = TargetKlass()
-        self.expected_format = ('%(class_name)s method %(method_name)s '
-                                'called with arguments %(args)s %(kwargs)s')
-        self.expected_data = {'class_name': MODULE_NAME + '.TargetKlass',
-                              'method_name': 'test_method',
-                              'args': (),
-                              'kwargs': {}}
+        logger = self.klass.test_method.im_func.func_closure[0].cell_contents
+        self.log_debug = mock.patch.object(logger, 'debug').start()
+
+    def _test_call_log(self, *args, **kwargs):
+        expected_format = ('%(class_name)s method %(method_name)s '
+                           'called with arguments %(args)s %(kwargs)s')
+        expected_data = {'class_name': '%s.%s' % (
+                         __name__,
+                         self.klass.__class__.__name__),
+                         'method_name': 'test_method',
+                         'args': args,
+                         'kwargs': kwargs}
+        self.klass.test_method(*args, **kwargs)
+        self.log_debug.assert_called_once_with(expected_format, expected_data)
 
     def test_call_log_all_args(self):
-        self.expected_data['args'] = (10, 20)
-        with mock.patch.object(call_log.LOG, 'debug') as log_debug:
-            self.klass.test_method(10, 20)
-            log_debug.assert_called_once_with(self.expected_format,
-                                              self.expected_data)
+        self._test_call_log(10, 20)
 
     def test_call_log_all_kwargs(self):
-        self.expected_data['kwargs'] = {'arg1': 10, 'arg2': 20}
-        with mock.patch.object(call_log.LOG, 'debug') as log_debug:
-            self.klass.test_method(arg1=10, arg2=20)
-            log_debug.assert_called_once_with(self.expected_format,
-                                              self.expected_data)
+        self._test_call_log(arg1=10, arg2=20)
 
     def test_call_log_known_args_unknown_args_kwargs(self):
-        self.expected_data['args'] = (10, 20, 30)
-        self.expected_data['kwargs'] = {'arg4': 40}
-        with mock.patch.object(call_log.LOG, 'debug') as log_debug:
-            self.klass.test_method(10, 20, 30, arg4=40)
-            log_debug.assert_called_once_with(self.expected_format,
-                                              self.expected_data)
+        self._test_call_log(10, 20, 30, arg4=40)
 
     def test_call_log_known_args_kwargs_unknown_kwargs(self):
-        self.expected_data['args'] = (10,)
-        self.expected_data['kwargs'] = {'arg2': 20, 'arg3': 30, 'arg4': 40}
-        with mock.patch.object(call_log.LOG, 'debug') as log_debug:
-            self.klass.test_method(10, arg2=20, arg3=30, arg4=40)
-            log_debug.assert_called_once_with(self.expected_format,
-                                              self.expected_data)
+        self._test_call_log(10, arg2=20, arg3=30, arg4=40)