From be50c33ee641cf6b7f3c8c08ef9328ff71a23c25 Mon Sep 17 00:00:00 2001
From: Dan Smith <dansmith@redhat.com>
Date: Fri, 20 Sep 2013 11:22:01 -0700
Subject: [PATCH] Log object lazy-loads

This is a trivial change that will be extremely helpful in tracking
down spurious lazy-loads and performance issues in the field. Simply
log to DEBUG any time we do a lazy-load of something. In practice,
this should be relatively rare.

Change-Id: I5e7bc058ba5ad17536a361367a0def5c4953643e
---
 nova/objects/instance.py            |  5 +++++
 nova/objects/service.py             | 10 ++++++++++
 nova/tests/objects/test_instance.py |  1 +
 3 files changed, 16 insertions(+)

diff --git a/nova/objects/instance.py b/nova/objects/instance.py
index 5ccb0d3b6337..7a7528e411cc 100644
--- a/nova/objects/instance.py
+++ b/nova/objects/instance.py
@@ -473,6 +473,11 @@ class Instance(base.NovaPersistentObject, base.NovaObject):
                 action='obj_load_attr',
                 reason='attribute %s not lazy-loadable' % attrname)
 
+        LOG.debug(_("Lazy-loading `%(attr)s' on %(name) uuid %(uuid)s"),
+                  {'attr': attrname,
+                   'name': self.obj_name(),
+                   'uuid': self.uuid,
+                   })
         # FIXME(comstud): This should be optimized to only load the attr.
         instance = self.__class__.get_by_uuid(self._context,
                                               uuid=self.uuid,
diff --git a/nova/objects/service.py b/nova/objects/service.py
index 3e3c82a60bdb..6d4ec0173925 100644
--- a/nova/objects/service.py
+++ b/nova/objects/service.py
@@ -18,6 +18,11 @@ from nova import exception
 from nova.objects import base
 from nova.objects import compute_node
 from nova.objects import utils
+from nova.openstack.common.gettextutils import _
+from nova.openstack.common import log as logging
+
+
+LOG = logging.getLogger(__name__)
 
 
 class Service(base.NovaPersistentObject, base.NovaObject):
@@ -65,6 +70,11 @@ class Service(base.NovaPersistentObject, base.NovaObject):
         return service
 
     def obj_load_attr(self, attrname):
+        LOG.debug(_("Lazy-loading `%(attr)s' on %(name)s id %(id)s"),
+                  {'attr': attrname,
+                   'name': self.obj_name(),
+                   'id': self.id,
+                   })
         if attrname != 'compute_node':
             raise exception.ObjectActionError(
                 action='obj_load_attr',
diff --git a/nova/tests/objects/test_instance.py b/nova/tests/objects/test_instance.py
index 1264694a7d41..58bec436505a 100644
--- a/nova/tests/objects/test_instance.py
+++ b/nova/tests/objects/test_instance.py
@@ -171,6 +171,7 @@ class _TestInstanceObject(object):
 
     def test_load_invalid(self):
         inst = instance.Instance()
+        inst.uuid = 'fake-uuid'
         self.assertRaises(exception.ObjectActionError,
                           inst.obj_load_attr, 'foo')