InventoryInUse exceptions with ironic virt driver

Bug #1771577 reported by Vladyslav Drok
12
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Medium
Matt Riedemann

Bug Description

Error can be seen here -- http://logs.openstack.org/39/554439/20/check/ironic-tempest-dsvm-ipa-wholedisk-bios-agent_ipmitool-tinyipa/e3c2ae3/logs/screen-n-cpu.txt.gz#_May_15_14_51_20_013490 :

May 15 14:51:20.013490 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager [None req-16f0955f-21d4-40b5-9f4f-14f6e2347ad5 service nova] Error updating resources for node 6b051502-a72e-4d72-a48a-23eef70f708f.: InventoryInUse: Inventory for ''CUSTOM_BAREMETAL'' on resource provider '2ec955b6-7aa2-4838-9dd6-fd9b279bff1e' in use.
May 15 14:51:20.013788 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager Traceback (most recent call last):
May 15 14:51:20.014078 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/compute/manager.py", line 7343, in update_available_resource_for_node
May 15 14:51:20.014359 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager rt.update_available_resource(context, nodename)
May 15 14:51:20.014679 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/compute/resource_tracker.py", line 680, in update_available_resource
May 15 14:51:20.014966 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager self._update_available_resource(context, resources)
May 15 14:51:20.015242 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 274, in inner
May 15 14:51:20.015547 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager return f(*args, **kwargs)
May 15 14:51:20.015846 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/compute/resource_tracker.py", line 704, in _update_available_resource
May 15 14:51:20.016135 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager self._init_compute_node(context, resources)
May 15 14:51:20.016413 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/compute/resource_tracker.py", line 561, in _init_compute_node
May 15 14:51:20.016692 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager self._update(context, cn)
May 15 14:51:20.016878 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/compute/resource_tracker.py", line 896, in _update
May 15 14:51:20.017048 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager inv_data,
May 15 14:51:20.017226 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/__init__.py", line 68, in set_inventory_for_provider
May 15 14:51:20.017425 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager parent_provider_uuid=parent_provider_uuid,
May 15 14:51:20.017651 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/__init__.py", line 37, in __run_method
May 15 14:51:20.017924 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager return getattr(self.instance, __name)(*args, **kwargs)
May 15 14:51:20.018196 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/report.py", line 1056, in set_inventory_for_provider
May 15 14:51:20.018475 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager self._update_inventory(context, rp_uuid, inv_data)
May 15 14:51:20.018701 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/report.py", line 66, in wrapper
May 15 14:51:20.018875 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager return f(self, *a, **k)
May 15 14:51:20.019092 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/report.py", line 986, in _update_inventory
May 15 14:51:20.019270 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager if self._update_inventory_attempt(context, rp_uuid, inv_data):
May 15 14:51:20.019460 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager File "/opt/stack/new/nova/nova/scheduler/client/report.py", line 928, in _update_inventory_attempt
May 15 14:51:20.019621 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager resource_provider=rp_uuid,
May 15 14:51:20.019805 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager InventoryInUse: Inventory for ''CUSTOM_BAREMETAL'' on resource provider '2ec955b6-7aa2-4838-9dd6-fd9b279bff1e' in use.
May 15 14:51:20.020018 ubuntu-xenial-inap-mtl01-0004032002 nova-compute[23854]: ERROR nova.compute.manager

I think this is happening as we have the compute.manager._update_resource_tracker call before the instance allocation deletion in the compute.manager._complete_deletion, so it introduces two problems:

1. if this _update_resource_tracker has out of date view from ironic virt driver node cache (as update_available_resource periodic happened before instance tear down started in ironic), we will delete the allocation without deleting the inventory, making the node resources 'free' until next update_available_resource periodic run
2. if _update_resource_tracker has up-to-date view from node cache, we will try to delete the inventory before deleting the allocation, which is what seems to be happening here.

Tags: ironic
Vladyslav Drok (vdrok)
Changed in nova:
assignee: nobody → Vladyslav Drok (vdrok)
description: updated
Changed in nova:
status: New → In Progress
Revision history for this message
Vladyslav Drok (vdrok) wrote :
Changed in nova:
assignee: Vladyslav Drok (vdrok) → Matt Riedemann (mriedem)
melanie witt (melwitt)
tags: added: iron
tags: added: ironic
removed: iron
Changed in nova:
importance: Undecided → Medium
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/517921
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=7e09641f849c323fd38006451256690ed66de80d
Submitter: Zuul
Branch: master

commit 7e09641f849c323fd38006451256690ed66de80d
Author: Vladyslav Drok <email address hidden>
Date: Mon Nov 6 13:16:44 2017 +0200

    ironic: Report resources as reserved when needed

    The main use case for this is during ironic node cleaning, when,
    instead of deleting the resource provider from placement we can
    just report the resources as temporarily reserved.

    This change also bumps placement API microversion used to update
    inventory to '1.26' which allows to have inventories with
    reserved value equal to total.

    Closes-Bug: 1771577
    blueprint: allow-reserved-equal-total-inventory
    Change-Id: I1fd85860c96e8690fbcf93c8a2f02178168bfd5a

Changed in nova:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 18.0.0.0b3

This issue was fixed in the openstack/nova 18.0.0.0b3 development milestone.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.