← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1705487] [NEW] placement logs an ERROR when PUT /allocation result in an invalid inventory

 

Public bug reported:

When an allocation requests on placement results in an invalid inventory due to the capacity is exceeded then placement return HTTP 409 properly but at the same time logs an ERROR log (see below). 
The ERROR log is not necessary as this is not a software error.

Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: [pid: 9543|app: 0|req: 790/1579] 192.168.122.191 () {66 vars in 1440 bytes} [Thu Jul 20 11:44:38 2017] PUT /placement/allocations/485c7480-939c-4b88-8c
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.requestlog [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Starting request: 192.168.122.191 "GET 
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Acquired semaphore "rc_cache" {{(pid=9542) lock /usr
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Releasing semaphore "rc_cache" {{(pid=9542) lock /us
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: INFO nova.api.openstack.placement.requestlog [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] 192.168.122.191 "GET /placement/allocati
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: [pid: 9542|app: 0|req: 790/1580] 192.168.122.191 () {60 vars in 1344 bytes} [Thu Jul 20 11:44:38 2017] GET /placement/allocations/9fff84b6-71e4-4f53-ad
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.requestlog [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Starting request: 192.168.122.191 "PUT 
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Bad inventory: InvalidInventor
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation Traceback (most recent call last):
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/api/openstack/placement/handlers/allocation.py", line 249, in _set_
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     allocations.create_all()
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1869, in create_all
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     self._set_allocations(self._context, self.objects)
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 979, in
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     return fn(*args, **kwargs)
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1829, in _set_allocations
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     before_gens = _check_capacity_exceeded(conn, allocs)
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1633, in _check_capacity_exceed
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     resource_provider=rp_uuid)
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation InvalidInventory: Inventory for 'CUSTOM_MAGIC' on resource provider 'a0a1d7f3-41f0-448f-ba36-e57
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation 
Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.wsgi_wrapper [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Placement API returning an error resp

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: placement

** Tags added: placement

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1705487

Title:
  placement logs an ERROR when PUT /allocation result in an invalid
  inventory

Status in OpenStack Compute (nova):
  New

Bug description:
  When an allocation requests on placement results in an invalid inventory due to the capacity is exceeded then placement return HTTP 409 properly but at the same time logs an ERROR log (see below). 
  The ERROR log is not necessary as this is not a software error.

  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: [pid: 9543|app: 0|req: 790/1579] 192.168.122.191 () {66 vars in 1440 bytes} [Thu Jul 20 11:44:38 2017] PUT /placement/allocations/485c7480-939c-4b88-8c
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.requestlog [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Starting request: 192.168.122.191 "GET 
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Acquired semaphore "rc_cache" {{(pid=9542) lock /usr
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] Releasing semaphore "rc_cache" {{(pid=9542) lock /us
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: INFO nova.api.openstack.placement.requestlog [None req-ce309a62-3819-4ccb-8491-828046235f2d service placement] 192.168.122.191 "GET /placement/allocati
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: [pid: 9542|app: 0|req: 790/1580] 192.168.122.191 () {60 vars in 1344 bytes} [Thu Jul 20 11:44:38 2017] GET /placement/allocations/9fff84b6-71e4-4f53-ad
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.requestlog [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Starting request: 192.168.122.191 "PUT 
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
  Jul 20 11:44:38 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Acquired semaphore "rc_cache" {{(pid=9543) lock /usr
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG oslo_concurrency.lockutils [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Releasing semaphore "rc_cache" {{(pid=9543) lock /us
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Bad inventory: InvalidInventor
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation Traceback (most recent call last):
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/api/openstack/placement/handlers/allocation.py", line 249, in _set_
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     allocations.create_all()
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1869, in create_all
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     self._set_allocations(self._context, self.objects)
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 979, in
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     return fn(*args, **kwargs)
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1829, in _set_allocations
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     before_gens = _check_capacity_exceeded(conn, allocs)
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation   File "/opt/stack/nova/nova/objects/resource_provider.py", line 1633, in _check_capacity_exceed
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation     resource_provider=rp_uuid)
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation InvalidInventory: Inventory for 'CUSTOM_MAGIC' on resource provider 'a0a1d7f3-41f0-448f-ba36-e57
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: ERROR nova.api.openstack.placement.handlers.allocation 
  Jul 20 11:44:39 ubuntu devstack@placement-api.service[9538]: DEBUG nova.api.openstack.placement.wsgi_wrapper [None req-149d9b07-f06c-4b5b-ae8d-504d2a51340e service placement] Placement API returning an error resp

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1705487/+subscriptions


Follow ups