From f80c0c732ae8323cc39bf9e720d6c9eb2534e90c Mon Sep 17 00:00:00 2001 From: Chris Spencer Date: Fri, 13 Jan 2017 14:36:34 -0700 Subject: [PATCH] Adding additional details to notification logs Improves tracking independent workflows. A log adapter was added to provide an easy means of prepending publisher ID and event type information. Change-Id: I5d2d8a369f99497b05c2a683989e656554d01b4f Closes-Bug: 1642623 --- devstack/lib/watcher | 2 +- .../decision_engine/model/notification/nova.py | 18 ++++++++++++++++-- .../notification/test_nova_notifications.py | 1 - 3 files changed, 17 insertions(+), 4 deletions(-) diff --git a/devstack/lib/watcher b/devstack/lib/watcher index 80723cc58..f76032913 100644 --- a/devstack/lib/watcher +++ b/devstack/lib/watcher @@ -154,7 +154,7 @@ function create_watcher_conf { setup_colorized_logging $WATCHER_CONF DEFAULT else # Show user_name and project_name instead of user_id and project_id - iniset $WATCHER_CONF DEFAULT logging_context_format_string "%(asctime)s.%(msecs)03d %(levelname)s %(name)s [%(request_id)s %(user_name)s %(project_name)s] %(instance)s%(message)s" + iniset $WATCHER_CONF DEFAULT logging_context_format_string "%(asctime)s.%(msecs)03d %(levelname)s %(name)s [%(request_id)s %(project_domain)s %(user_name)s %(project_name)s] %(instance)s%(message)s" fi # Register SSL certificates if provided diff --git a/watcher/decision_engine/model/notification/nova.py b/watcher/decision_engine/model/notification/nova.py index 8e450f790..9695ec78c 100644 --- a/watcher/decision_engine/model/notification/nova.py +++ b/watcher/decision_engine/model/notification/nova.py @@ -17,7 +17,6 @@ # limitations under the License. from oslo_log import log - from watcher._i18n import _LI, _LW from watcher.common import exception from watcher.common import nova_helper @@ -220,6 +219,8 @@ class ServiceUpdated(VersionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -262,6 +263,8 @@ class InstanceCreated(VersionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -269,7 +272,6 @@ class InstanceCreated(VersionnedNotificationEndpoint): metadata=metadata)) LOG.debug(payload) instance_data = payload['nova_object.data'] - instance_uuid = instance_data['uuid'] node_uuid = instance_data.get('host') instance = self.get_or_create_instance(instance_uuid, node_uuid) @@ -296,6 +298,8 @@ class InstanceUpdated(VersionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -321,6 +325,8 @@ class InstanceDeletedEnd(VersionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -354,6 +360,8 @@ class LegacyInstanceUpdated(UnversionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -379,6 +387,8 @@ class LegacyInstanceCreatedEnd(UnversionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -404,6 +414,8 @@ class LegacyInstanceDeletedEnd(UnversionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, @@ -435,6 +447,8 @@ class LegacyLiveMigratedEnd(UnversionnedNotificationEndpoint): ) def info(self, ctxt, publisher_id, event_type, payload, metadata): + ctxt.request_id = metadata['message_id'] + ctxt.project_domain = event_type LOG.info(_LI("Event '%(event)s' received from %(publisher)s " "with metadata %(metadata)s") % dict(event=event_type, diff --git a/watcher/tests/decision_engine/model/notification/test_nova_notifications.py b/watcher/tests/decision_engine/model/notification/test_nova_notifications.py index 8b07e4143..a8f283dff 100644 --- a/watcher/tests/decision_engine/model/notification/test_nova_notifications.py +++ b/watcher/tests/decision_engine/model/notification/test_nova_notifications.py @@ -199,7 +199,6 @@ class TestNovaNotifications(NotificationTestCase): m_nova_helper_cls.return_value = mock.Mock( get_compute_node_by_hostname=m_get_compute_node_by_hostname, name='m_nova_helper') - compute_model = self.fake_cdmc.generate_scenario_3_with_2_nodes() self.fake_cdmc.cluster_data_model = compute_model handler = novanotification.InstanceUpdated(self.fake_cdmc)