Merge "Cleaned up rpc loggingutils"

designate/central/rpcapi.py

@@ -16,9 +16,9 @@
 from oslo_log import log as logging
 import oslo_messaging as messaging
 
+from designate.common.decorators import rpc as rpc_decorator
 from designate.common import profiler
 import designate.conf
-from designate.loggingutils import rpc_logging
 from designate import rpc
 
 
@@ -34,7 +34,7 @@ def reset():
 
 
 @profiler.trace_cls("rpc")
-@rpc_logging(LOG, 'central')
+@rpc_decorator.rpc_logging(LOG, 'central')
 class CentralAPI:
     """
     Client side of the central RPC API.
@@ -79,7 +79,7 @@ class CentralAPI:
     # This can be for a few reasons - some methods my not actually call over
     # RPC, or may be so noisy that logging them is not useful
     # This should be an array of strings that match the function names
-    LOGGING_BLACKLIST = ['update_service_status']
+    RPC_LOGGING_DISALLOW = ['update_service_status']
 
     def __init__(self, topic=None):
         self.topic = topic if topic else CONF['service:central'].topic

designate/common/decorators/rpc.py

@@ -11,6 +11,7 @@
 # under the License.
 
 import functools
+import inspect
 import threading
 
 from oslo_messaging.rpc import dispatcher as rpc_dispatcher
@@ -18,6 +19,12 @@ from oslo_messaging.rpc import dispatcher as rpc_dispatcher
 import designate.exceptions
 
 
+RPC_LOGGING_DISALLOW = [
+    'get_instance',
+    '__init__'
+]
+
+
 class ExceptionThreadLocal(threading.local):
     def __init__(self):
         super().__init__()
@@ -47,3 +54,27 @@ def expected_exceptions():
                 cls.exception_thread_local.reset_depth()
         return exception_wrapper
     return outer
+
+
+def log_rpc_call(func, rpcapi, logger):
+    def wrapped(*args, **kwargs):
+        logger.debug(
+            'Calling designate.%(rpcapi)s.%(function)s() over RPC',
+            {
+                'function': func.__name__,
+                'rpcapi': rpcapi
+            }
+        )
+        return func(*args, **kwargs)
+    return wrapped
+
+
+def rpc_logging(logger, rpcapi):
+    def wrapper(cls):
+        disallow = getattr(cls, 'RPC_LOGGING_DISALLOW', [])
+        disallow.extend(RPC_LOGGING_DISALLOW)
+        for name, value in inspect.getmembers(cls, inspect.ismethod):
+            if name not in disallow:
+                setattr(cls, name, log_rpc_call(value, rpcapi, logger))
+        return cls
+    return wrapper

designate/loggingutils.py

@@ -1,43 +0,0 @@
-# Copyright 2016 Hewlett Packard Enterprise Development Company LP
-#
-# 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 inspect
-
-LOG = {}
-
-
-def log_rpc_call(func, rpcapi, logger):
-    def wrapped(*args, **kwargs):
-        logger.debug("Calling designate.%(rpcapi)s.%(function)s() "
-                     "over RPC", {'function': func.__name__,
-                                  'rpcapi': rpcapi})
-        return func(*args, **kwargs)
-    return wrapped
-
-
-LOGGING_BLACKLIST = [
-    'get_instance',
-    '__init__'
-]
-
-
-def rpc_logging(logger, rpcapi):
-    def wrapper(cls):
-        CLASS_BLACKLIST = getattr(cls, 'LOGGING_BLACKLIST', [])
-        BLACKLIST = CLASS_BLACKLIST + LOGGING_BLACKLIST
-        for name, m in inspect.getmembers(cls, inspect.ismethod):
-            if name not in BLACKLIST:
-                setattr(cls, name, log_rpc_call(m, rpcapi, logger))
-        return cls
-    return wrapper

designate/tests/fixtures.py

@@ -231,12 +231,6 @@ class StandardLogging(fixtures.Fixture):
         root = std_logging.getLogger()
         root.setLevel(std_logging.DEBUG)
 
-        # supports collecting debug level for local runs
-        if os.environ.get('OS_DEBUG') in _TRUE_VALUES:
-            level = std_logging.DEBUG
-        else:
-            level = std_logging.INFO
-
         # Collect logs
         fs = '%(asctime)s %(levelname)s [%(name)s] %(message)s'
         self.logger = self.useFixture(
@@ -244,17 +238,7 @@ class StandardLogging(fixtures.Fixture):
         # TODO(sdague): why can't we send level through the fake
         # logger? Tests prove that it breaks, but it's worth getting
         # to the bottom of.
-        root.handlers[0].setLevel(level)
-
-        if level > std_logging.DEBUG:
-            # Just attempt to format debug level logs, but don't save them
-            handler = NullHandler()
-            self.useFixture(fixtures.LogHandler(handler, nuke_handlers=False))
-            handler.setLevel(std_logging.DEBUG)
-
-            # Don't log every single DB migration step
-            std_logging.getLogger(
-                'migrate.versioning.api').setLevel(std_logging.WARNING)
+        root.handlers[0].setLevel(std_logging.DEBUG)
 
         # At times we end up calling back into main() functions in
         # testing. This has the possibility of calling logging.setup

designate/tests/unit/common/test_rpc_logging.py

@@ -0,0 +1,55 @@
+# 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.
+
+
+from oslo_log import log as logging
+import oslotest.base
+
+from designate.common.decorators import rpc
+import designate.conf
+from designate.tests import fixtures
+
+
+CONF = designate.conf.CONF
+LOG = logging.getLogger(__name__)
+
+
+@rpc.rpc_logging(LOG, 'test')
+class RPCLog:
+    RPC_LOGGING_DISALLOW = ['ignore']
+
+    @classmethod
+    def test(cls):
+        return None
+
+    @classmethod
+    def ignore(cls):
+        return None
+
+
+class TestRPCLogging(oslotest.base.BaseTestCase):
+    def setUp(self):
+        super().setUp()
+        self.stdlog = fixtures.StandardLogging()
+        self.useFixture(self.stdlog)
+
+    def test_rpc_logging(self):
+        RPCLog.test()
+
+        self.assertIn(
+            'Calling designate.test.test() over RPC', self.stdlog.logger.output
+        )
+
+    def test_rpc_disallow_logging(self):
+        RPCLog.ignore()
+
+        self.assertFalse(self.stdlog.logger.output)

designate/worker/rpcapi.py

@@ -16,9 +16,9 @@
 from oslo_log import log as logging
 import oslo_messaging as messaging
 
+from designate.common.decorators import rpc as rpc_decorator
 from designate.common import profiler
 import designate.conf
-from designate.loggingutils import rpc_logging
 from designate import rpc
 
 
@@ -29,7 +29,7 @@ WORKER_API = None
 
 
 @profiler.trace_cls("rpc")
-@rpc_logging(LOG, 'worker')
+@rpc_decorator.rpc_logging(LOG, 'worker')
 class WorkerAPI:
     """
     Client side of the worker RPC API.