diff --git a/oslo_messaging/_drivers/impl_fake.py b/oslo_messaging/_drivers/impl_fake.py index c5476fdf8..dc6439dc4 100644 --- a/oslo_messaging/_drivers/impl_fake.py +++ b/oslo_messaging/_drivers/impl_fake.py @@ -16,6 +16,7 @@ import copy import threading import time +import uuid from oslo_serialization import jsonutils from six import moves @@ -29,6 +30,7 @@ class FakeIncomingMessage(base.RpcIncomingMessage): super(FakeIncomingMessage, self).__init__(ctxt, message) self.requeue_callback = requeue self._reply_q = reply_q + self.msg_id = str(uuid.uuid4()) def reply(self, reply=None, failure=None): if self._reply_q: diff --git a/oslo_messaging/rpc/server.py b/oslo_messaging/rpc/server.py index b16d77fa6..f1deff707 100644 --- a/oslo_messaging/rpc/server.py +++ b/oslo_messaging/rpc/server.py @@ -122,6 +122,7 @@ A simple example of an RPC server with multiple endpoints might be:: import logging import sys +import time from oslo_messaging import exceptions from oslo_messaging.rpc import dispatcher as rpc_dispatcher @@ -151,6 +152,12 @@ class RPCServer(msg_server.MessageHandlingServer): def _process_incoming(self, incoming): message = incoming[0] + rpc_method = message.message.get('method') + start = time.time() + LOG.debug("Receive incoming message with id %(msg_id)s and " + "method: %(method)s.", + {"msg_id": message.msg_id, + "method": rpc_method}) # TODO(sileht): We should remove that at some point and do # this directly in the driver @@ -176,8 +183,19 @@ class RPCServer(msg_server.MessageHandlingServer): try: if failure is None: message.reply(res) + LOG.debug("Replied success message with id %(msg_id)s and " + "method: %(method)s. Time elapsed: %(elapsed).3f", + {"msg_id": message.msg_id, + "method": rpc_method, + "elapsed": (time.time() - start)}) else: message.reply(failure=failure) + LOG.debug("Replied failure for incoming message with " + "id %(msg_id)s and method: %(method)s. " + "Time elapsed: %(elapsed).3f", + {"msg_id": message.msg_id, + "method": rpc_method, + "elapsed": (time.time() - start)}) except exceptions.MessageUndeliverable as e: LOG.exception( "MessageUndeliverable error, " diff --git a/oslo_messaging/tests/rpc/test_server.py b/oslo_messaging/tests/rpc/test_server.py index 693e88a52..cf2d4ba0a 100644 --- a/oslo_messaging/tests/rpc/test_server.py +++ b/oslo_messaging/tests/rpc/test_server.py @@ -400,7 +400,7 @@ class TestRPCServer(test_utils.BaseTestCase, ServerSetupMixin): except Exception as ex: self.assertIsInstance(ex, ValueError) self.assertEqual('dsfoo', str(ex)) - self.assertTrue(len(debugs) == 0) + self.assertTrue(len(debugs) == 2) self.assertGreater(len(errors), 0) else: self.assertTrue(False)