RT: improve logging in _update_usage_from_migration

While working on some code which performs a resize_claim
I was finding that the actual new_flavor usage was not being
tracked on the destination host. It was a coding mistake
because I had not set instance.new_flavor before calling
resize_claim but that is extremely tightly coupled behavior
with how prep_resize works and the bowels of the
_update_usage_from_migration code works. This change simply
improves logging in the _update_usage_from_migration method
for debugging and updates the resize_claim docstring to
indicate the coupled nature of instance.new_flavor when calling
that method.

Change-Id: Ieb539c9a0cfbac743c579a1633234537a8e3e3ee

nova/compute/resource_tracker.py

@@ -247,7 +247,11 @@ class ResourceTracker(object):
     @utils.synchronized(COMPUTE_RESOURCE_SEMAPHORE)
     def resize_claim(self, context, instance, instance_type, nodename,
                      migration, image_meta=None, limits=None):
-        """Create a claim for a resize or cold-migration move."""
+        """Create a claim for a resize or cold-migration move.
+
+        Note that this code assumes ``instance.new_flavor`` is set when
+        resizing with a new flavor.
+        """
         return self._move_claim(context, instance, instance_type, nodename,
                                 migration, image_meta=image_meta,
                                 limits=limits)
@@ -1033,7 +1037,8 @@ class ResourceTracker(object):
             return
 
         uuid = migration.instance_uuid
-        LOG.info("Updating resource usage from migration", instance_uuid=uuid)
+        LOG.info("Updating resource usage from migration %s", migration.uuid,
+                 instance_uuid=uuid)
 
         incoming = (migration.dest_compute == self.host and
                     migration.dest_node == nodename)
@@ -1080,6 +1085,8 @@ class ResourceTracker(object):
                 'numa_topology', instance)
             # Allocate pci device(s) for the instance.
             sign = 1
+            LOG.debug('Starting to track incoming migration %s with flavor %s',
+                      migration.uuid, itype.flavorid, instance=instance)
 
         elif outbound and not tracked:
             # instance migrated, but record usage for a possible revert:
@@ -1087,6 +1094,8 @@ class ResourceTracker(object):
                     migration)
             numa_topology = self._get_migration_context_resource(
                 'numa_topology', instance, prefix='old_')
+            LOG.debug('Starting to track outgoing migration %s with flavor %s',
+                      migration.uuid, itype.flavorid, instance=instance)
 
         if itype:
             cn = self.compute_nodes[nodename]

nova/tests/unit/compute/test_resource_tracker.py

@@ -241,7 +241,8 @@ _MIGRATION_FIXTURES = {
         old_instance_type_id=1,
         new_instance_type_id=2,
         migration_type='resize',
-        status='migrating'
+        status='migrating',
+        uuid=uuids.source_only,
     ),
     # A migration that has only this compute node as the dest host
     'dest-only': objects.Migration(
@@ -254,7 +255,8 @@ _MIGRATION_FIXTURES = {
         old_instance_type_id=1,
         new_instance_type_id=2,
         migration_type='resize',
-        status='migrating'
+        status='migrating',
+        uuid=uuids.dest_only,
     ),
     # A migration that has this compute node as both the source and dest host
     'source-and-dest': objects.Migration(
@@ -267,7 +269,8 @@ _MIGRATION_FIXTURES = {
         old_instance_type_id=1,
         new_instance_type_id=2,
         migration_type='resize',
-        status='migrating'
+        status='migrating',
+        uuid=uuids.source_and_dest,
     ),
     # A migration that has this compute node as destination and is an evac
     'dest-only-evac': objects.Migration(
@@ -280,7 +283,8 @@ _MIGRATION_FIXTURES = {
         old_instance_type_id=2,
         new_instance_type_id=None,
         migration_type='evacuation',
-        status='pre-migrating'
+        status='pre-migrating',
+        uuid=uuids.dest_only_evac,
     ),
 }
 
@@ -2142,7 +2146,8 @@ class TestResize(BaseTestCase):
             old_instance_type_id=1,
             new_instance_type_id=2,
             migration_type='resize',
-            status='migrating'
+            status='migrating',
+            uuid=uuids.migration,
         )
         new_flavor = _INSTANCE_TYPE_OBJ_FIXTURES[2]
 
@@ -2266,7 +2271,8 @@ class TestResize(BaseTestCase):
             old_instance_type_id=1,
             new_instance_type_id=2,
             migration_type='resize',
-            status='migrating'
+            status='migrating',
+            uuid=uuids.migration,
         )
         new_flavor = _INSTANCE_TYPE_OBJ_FIXTURES[2]
 
@@ -2370,6 +2376,7 @@ class TestResize(BaseTestCase):
             migration_type='resize',
             status='migrating',
             instance=instance,
+            uuid=uuids.migration,
         )
         mig_context_obj = objects.MigrationContext(
             instance_uuid=instance.uuid,
@@ -2501,6 +2508,7 @@ class TestResize(BaseTestCase):
             migration_type='resize',
             status='migrating',
             instance=instance1,
+            uuid=uuids.migration1,
         )
         mig_context_obj1 = objects.MigrationContext(
             instance_uuid=instance1.uuid,
@@ -2532,6 +2540,7 @@ class TestResize(BaseTestCase):
             migration_type='resize',
             status='migrating',
             instance=instance1,
+            uuid=uuids.migration2,
         )
         mig_context_obj2 = objects.MigrationContext(
             instance_uuid=instance2.uuid,
@@ -2630,7 +2639,8 @@ class TestRebuild(BaseTestCase):
             source_compute='fake-other-compute',
             source_node='fake-other-node',
             status='accepted',
-            migration_type='evacuation'
+            migration_type='evacuation',
+            uuid=uuids.migration,
         )
         instance = objects.Instance(
             id=1,