Race condition in quota estimation may lead remaining quota to get negative

[Eugene Nikanorov]

The following was discovered on decently loaded cloud on Icehouse (5.1):

<183>Mar 15 14:11:20 node-7 nova-api 2016-03-15 14:11:20.619 147786 DEBUG nova.compute.api [req-ed5b1f57-d591-40b0-a7af-921ecd1d8fd8 None] max count reduced from 1 to -12 due to network port quota _create_instance /usr/lib/python2.6/site-packages/nova/compute/api.py:979
<180>Mar 15 14:11:20 node-7 nova-api 2016-03-15 14:11:20.635 147786 WARNING nova.db.sqlalchemy.api [req-ed5b1f57-d591-40b0-a7af-921ecd1d8fd8 None] Change will make usage less than 0 for the following resources: ['instances', 'ram', 'cores']
<183>Mar 15 14:11:20 node-7 nova-api 2016-03-15 14:11:20.635 147786 DEBUG nova.quota [req-ed5b1f57-d591-40b0-a7af-921ecd1d8fd8 None] Created reservations ['ac197836-f95e-46ea-9802-827f0d11829f', '47c7c9e1-0de0-4aea-b784-bc2f3193c559', '2cd1ef69-c434-4ff6-8b31-2b6f0832c344'] reserve /usr/lib/python2.6/site-packages/nova/quota.py:1272
<183>Mar 15 14:11:20 node-7 nova-api 2016-03-15 14:11:20.635 147786 DEBUG nova.compute.api [req-ed5b1f57-d591-40b0-a7af-921ecd1d8fd8 None] Going to run -12 instances... _provision_instances /usr/lib/python2.6/site-packages/nova/compute/api.py:812
Related upstream bug: https://bugs.launchpad.net/nova/+bug/1549032
...
...
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args)
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1070, in dispatch
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack return method(req=request, **action_args)
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/servers.py", line 1009, in create
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack server = self._view_builder.create(req, instances[0])
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack IndexError: list index out of range
2016-03-15 14:11:20.659 147786 TRACE nova.api.openstack

Related upstream bug: https://bugs.launchpad.net/nova/+bug/1549032

While the fix suggests proper check, the root cause is some kind of race condition that is yet to be discovered.

[Eugene Nikanorov (enikanorov)]

Adding all existing milestones as the fix was committed upstream just 3 weeks ago.

[Roman Podoliaka (rpodolyaka)]

The commit is in Mitaka and our 9.0 downstream branch:

rpodolyaka@rpodolyaka-pc:~/src/nova$ git branch -a --contains e015a98b9e99dca7b97e97bb48af4392fd34dddb | grep mirantis
  remotes/mirantis/9.0/mitaka
  remotes/mirantis/master
  remotes/mirantis/stable/mitaka
rpodolyaka@rpodolyaka-pc:~/src/nova$ git show e015a98b9e99dca7b97e97bb48af4392fd34dddb
commit e015a98b9e99dca7b97e97bb48af4392fd34dddb
Author: Chris Friesen <email address hidden>
Date: Tue Feb 23 17:27:00 2016 -0600

    check max_net_count against min_count when booting

    If the user has specified a min_count when booting instances, and
    our calculated max_net_count is smaller than the specified min_count
    then we want to fail with an easily-interpreted error.

    Change-Id: I7f8bde68e315dc39942faff4065db927e477e1f1
    Closes-Bug: #1549032

[Rodion Tikunov (rtikunov)]

Could you provide some steps how to reproduce the bug?

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: openstack-ci/fuel-8.0/liberty
Change author: Chris Friesen <email address hidden>
Review: https://review.fuel-infra.org/19475

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: openstack-ci/fuel-7.0/2015.1.0
Change author: Rodion Tikunov <email address hidden>
Review: https://review.fuel-infra.org/19500

[Rodion Tikunov (rtikunov)]

Steps to reproduce:
1) Deploy OpenStack with one controller and one compute node
2) Create project with quota
source openrc
openstack project create --description 'test1' test1
openstack user create --project test1 --password test1test test1
neutron quota-update --tenant_id test1 --network 3 --subnet 3 --port 3 -- --floatingip 3 --router 3
3) Create network in that project
export OS_TENANT_NAME='test1'
export OS_PROJECT_NAME='test1'
export OS_USERNAME='test1'
export OS_PASSWORD='test1test'

neutron net-create --prefix 192.168.120.0/24 test1
neutron subnet-create test1 192.168.120.0/24
4) Patching file /usr/lib/python2.7/dist-packages/nova/compute/api.py
patch
--- /usr/lib/python2.7/dist-packages/nova/compute/api.py.orig 2016-04-11 15:29:48.655077119 +0000
+++ /usr/lib/python2.7/dist-packages/nova/compute/api.py 2016-04-11 15:30:42.315261962 +0000
@@ -1183,6 +1183,7 @@
         # max_net_count is the maximum number of instances requested by the
         # user adjusted for any network quota constraints, including
         # consideration of connections to each requested network
+ max_net_count = -12
         if max_net_count == 0:
             raise exception.PortLimitExceeded()
         elif max_net_count < max_count:
5) Restart nova services
rm /usr/lib/python2.7/dist-packages/nova/compute/api.pyc
service nova-scheduler restart; service nova-api restart; service nova-scheduler restart
6) Create instances
nova boot --image TestVM --flavor m1.tiny --min-count 2 --max-count 3 --nic net-id=1cc2f10c-d11f-4544-94c3-f76edd8ae2e3 test1
Result:
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<type 'exceptions.IndexError'> (HTTP 500) (Request-ID: req-ba9ec03b-bb8b-438e-bc6c-b323b8257ab2)

in logs
2016-04-11 15:26:58.246 4153229 DEBUG nova.compute.api [req-644d6ed7-1973-482f-92d1-3c3a5d57f911 14bd92c40d7d4b92bbb24955cd6e99ff 67a8970da66e4cd0917e374bda795a79 - - -] max count reduced from 3 to -12 due
 to network port quota _create_instance /usr/lib/python2.7/dist-packages/nova/compute/api.py:1195
2016-04-11 15:26:58.251 4153229 DEBUG nova.quota [req-644d6ed7-1973-482f-92d1-3c3a5d57f911 14bd92c40d7d4b92bbb24955cd6e99ff 67a8970da66e4cd0917e374bda795a79 - - -] Created reservations [] reserve /usr/lib/
python2.7/dist-packages/nova/quota.py:1345
2016-04-11 15:26:58.252 4153229 DEBUG nova.compute.api [req-644d6ed7-1973-482f-92d1-3c3a5d57f911 14bd92c40d7d4b92bbb24955cd6e99ff 67a8970da66e4cd0917e374bda795a79 - - -] Going to run -12 instances... _prov
ision_instances /usr/lib/python2.7/dist-packages/nova/compute/api.py:1014
2016-04-11 15:26:58.336 4153229 ERROR nova.api.openstack.extensions [req-644d6ed7-1973-482f-92d1-3c3a5d57f911 14bd92c40d7d4b92bbb24955cd6e99ff 67a8970da66e4cd0917e374bda795a79 - - -] Unexpected exception i
n API method
2016-04-11 15:26:58.336 4153229 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2016-04-11 15:26:58.336 4153229 ERROR nova.api.openstack.extensions File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 478, in wrapped
2016-04-11 15:26:58.336 4153229 ERROR nova.api.openst...

[Fuel Devops McRobotson (fuel-devops-robot)]

Fix proposed to branch: openstack-ci/fuel-6.1/2014.2
Change author: Rodion Tikunov <email address hidden>
Review: https://review.fuel-infra.org/19671

[TatyanaGladysheva (tgladysheva)]

Verified on MOS 7.0 + MU6 updates using steps from [0].

Actual result:
root@node-1:~# nova boot --image TestVM --flavor m1.tiny --min-count 2 --max-count 3 --nic net-id=e85aebf5-84d5-4fd0-b720-8767a410a25c test1
ERROR (Forbidden): Maximum number of ports exceeded (HTTP 403) (Request-ID: req-3e203d50-228d-449e-a7f6-998630a0df53)

[0] https://bugs.launchpad.net/mos/+bug/1557730/comments/6

[Ekaterina Shutova (eshutova)]

Verified on MOS 8.0 + mu4 updates.
Result with fix:
root@node-2:~# nova boot --image TestVM --flavor m1.tiny --min-count 2 --max-count 3 --nic net-id=5cab1a63-b538-4ac7-b2b0-9cca5533b362 test1
ERROR (Forbidden): Maximum number of ports exceeded (HTTP 403) (Request-ID: req-cbcdc554-19d7-4e8f-8eaa-b386c1d399f6)