Additional logging for placement API

This logs the allocations when we create or delete them.

This also logs some of the exceptions as LOG.exception. While they are
not always fatal or problematic, during this first cycle with the
placement-api being a thing, being more loud about odd behavior is
good. It took a lot of staring at the logs to realize how often we
were erroring in non useful ways that weren't entirely obvious.

Add __repr__ to both AllocationList and UsageList to make building
sensible log messages much simpler.

Change-Id: I8dc77408eff79b35845f6b9b5dcea6ed211cc858

nova/api/openstack/placement/handlers/allocation.py

@@ -14,14 +14,18 @@
 import collections
 
 import jsonschema
+from oslo_log import log as logging
 from oslo_serialization import jsonutils
 import webob
 
 from nova.api.openstack.placement import util
 from nova import exception
+from nova.i18n import _LE
 from nova import objects
 
 
+LOG = logging.getLogger(__name__)
+
 ALLOCATION_SCHEMA = {
     "type": "object",
     "properties": {
@@ -248,16 +252,20 @@ def set_allocations(req):
             allocation_objects.append(allocation)
 
     allocations = objects.AllocationList(context, objects=allocation_objects)
+
     try:
         allocations.create_all()
+        LOG.debug("Successfully wrote allocations %s", allocations)
     # InvalidInventory is a parent for several exceptions that
     # indicate either that Inventory is not present, or that
     # capacity limits have been exceeded.
     except exception.InvalidInventory as exc:
+        LOG.exception(_LE("Bad inventory"))
         raise webob.exc.HTTPConflict(
             'Unable to allocate inventory: %s' % exc,
             json_formatter=util.json_error_formatter)
     except exception.ConcurrentUpdateDetected as exc:
+        LOG.exception(_LE("Concurrent Update"))
         raise webob.exc.HTTPConflict(
             'Inventory changed while attempting to allocate: %s' % exc,
             json_formatter=util.json_error_formatter)
@@ -279,6 +287,7 @@ def delete_allocations(req):
             "No allocations for consumer '%s'" % consumer_uuid,
             json_formatter=util.json_error_formatter)
     allocations.delete_all()
+    LOG.debug("Successfully deleted allocations %s", allocations)
 
     req.response.status = 204
     req.response.content_type = None

nova/objects/resource_provider.py

@@ -871,6 +871,10 @@ class AllocationList(base.ObjectListBase, base.NovaObject):
     def delete_all(self):
         self._delete_allocations(self._context, self.objects)
 
+    def __repr__(self):
+        strings = [repr(x) for x in self.objects]
+        return "AllocationList[" + ", ".join(strings) + "]"
+
 
 @base.NovaObjectRegistry.register
 class Usage(base.NovaObject):
@@ -930,3 +934,7 @@ class UsageList(base.ObjectListBase, base.NovaObject):
     def get_all_by_resource_provider_uuid(cls, context, rp_uuid):
         usage_list = cls._get_all_by_resource_provider_uuid(context, rp_uuid)
         return base.obj_make_list(context, cls(context), Usage, usage_list)
+
+    def __repr__(self):
+        strings = [repr(x) for x in self.objects]
+        return "UsageList[" + ", ".join(strings) + "]"