yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1731668] Re: placement: claim allocations fails with IndexError in _ensure_lookup_table_entry

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1731668@xxxxxxxxxxxxxxxxxx>
Date: Sat, 02 Dec 2017 02:55:31 -0000
Reply-to: Bug 1731668 <1731668@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.openstack.org/523192
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=31751a7149a3bb4b51087aecdc3b14c061c60d9b
Submitter: Zuul
Branch:    master

commit 31751a7149a3bb4b51087aecdc3b14c061c60d9b
Author: Jay Pipes <jaypipes@xxxxxxxxx>
Date:   Mon Nov 27 13:50:00 2017 -0500

    Use oslo_db Session in resource_provider.py
    
    In a number of places in resource_provider.py, we're checking for
    DBDuplicateError after running conn.execute(). And "conn" is an
    SQLAlchemy Connection object. The issue is that DBDuplicateError is not
    an SQLAlchemy exception. Instead, it is an oslo_db-specific exception
    that is used to mask differences between DB drivers that variably return
    an OperationalError or an IntegrityError when a duplicate key is found
    [1].
    
    In practice, what this means is that all calling locations that use the
    straight "conn.execute()" calling sequence cannot rely on catching
    DBDuplicateError (because SQLAlchemy's Connection.execute() method will
    never raise it). Instead, all of those calling locations needed to be
    updated to use context.session.execute() instead. This allows
    DBDuplicateError to be caught properly.
    
    In addition, all the manual construction of transactions in
    resource_provider.py that did:
    
     with conn.begin()
    
    needed to have those manual begin() calls removed. The reason is that
    oslo_db's Session object (which is what is injected by the enginefacade
    into the nova.context.RequestContext) automatically handles creation,
    commit and rollback of transactions based on whether the source
    entrypoint is a writer or reader context.
    
    Closes-bug: #1731668
    [1]: https://github.com/openstack/oslo.db/blob/stable/pike/oslo_db/sqlalchemy/exc_filters.py#L95-L153
    
    Change-Id: Ic5860cbef4d47e847bb5f190526b5a8ea3c33298


** Changed in: nova
       Status: In Progress => Fix Released

-- 
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/1731668

Title:
  placement: claim allocations fails with IndexError in
  _ensure_lookup_table_entry

Status in OpenStack Compute (nova):
  Fix Released

Bug description:
  http://logs.openstack.org/73/513473/2/check/legacy-tempest-dsvm-
  cells/be1a0fa/logs/screen-placement-api.txt.gz#_Nov_10_01_14_05_230382

  Nov 10 01:14:05.230382 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler [None req-1f685650-1d9a-4194-b033-31a419813464 service placement] Uncaught exception: IndexError: list index out of range
  Nov 10 01:14:05.230656 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler Traceback (most recent call last):
  Nov 10 01:14:05.230866 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/handler.py", line 217, in __call__
  Nov 10 01:14:05.231069 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return dispatch(environ, start_response, self._map)
  Nov 10 01:14:05.231302 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/handler.py", line 144, in dispatch
  Nov 10 01:14:05.231489 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return handler(environ, start_response)
  Nov 10 01:14:05.231701 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 131, in __call__
  Nov 10 01:14:05.231942 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     resp = self.call_func(req, *args, **self.kwargs)
  Nov 10 01:14:05.232157 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/wsgi_wrapper.py", line 29, in call_func
  Nov 10 01:14:05.232382 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     super(PlacementWsgify, self).call_func(req, *args, **kwargs)
  Nov 10 01:14:05.232611 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 196, in call_func
  Nov 10 01:14:05.232841 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return self.func(req, *args, **kwargs)
  Nov 10 01:14:05.233056 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/microversion.py", line 269, in decorated_func
  Nov 10 01:14:05.233258 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return _find_method(f, version)(req, *args, **kwargs)
  Nov 10 01:14:05.233456 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/util.py", line 147, in decorated_function
  Nov 10 01:14:05.233689 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return f(req)
  Nov 10 01:14:05.233897 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/handlers/allocation.py", line 282, in set_allocations
  Nov 10 01:14:05.234101 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return _set_allocations(req, ALLOCATION_SCHEMA_V1_8)
  Nov 10 01:14:05.234222 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/api/openstack/placement/handlers/allocation.py", line 248, in _set_allocations
  Nov 10 01:14:05.234337 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     allocations.create_all()
  Nov 10 01:14:05.234453 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/objects/resource_provider.py", line 1889, in create_all
  Nov 10 01:14:05.234567 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     self._set_allocations(self._context, self.objects)
  Nov 10 01:14:05.234685 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 150, in wrapper
  Nov 10 01:14:05.234793 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     ectxt.value = e.inner_exc
  Nov 10 01:14:05.234902 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  Nov 10 01:14:05.235015 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     self.force_reraise()
  Nov 10 01:14:05.235129 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Nov 10 01:14:05.235242 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     six.reraise(self.type_, self.value, self.tb)
  Nov 10 01:14:05.235352 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
  Nov 10 01:14:05.235460 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return f(*args, **kwargs)
  Nov 10 01:14:05.235577 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 984, in wrapper
  Nov 10 01:14:05.235701 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return fn(*args, **kwargs)
  Nov 10 01:14:05.235821 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/objects/resource_provider.py", line 1817, in _set_allocations
  Nov 10 01:14:05.235936 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     alloc.ensure_consumer_project_user(conn)
  Nov 10 01:14:05.236049 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/objects/resource_provider.py", line 1469, in ensure_consumer_project_user
  Nov 10 01:14:05.236163 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     pid = _ensure_project(conn, self.project_id)
  Nov 10 01:14:05.236272 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/objects/resource_provider.py", line 1691, in _ensure_project
  Nov 10 01:14:05.236391 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return _ensure_lookup_table_entry(conn, _PROJECT_TBL, external_id)
  Nov 10 01:14:05.236506 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler   File "/opt/stack/new/nova/nova/objects/resource_provider.py", line 1680, in _ensure_lookup_table_entry
  Nov 10 01:14:05.236617 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler     return res[0][0]
  Nov 10 01:14:05.236727 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler IndexError: list index out of range
  Nov 10 01:14:05.236912 ubuntu-xenial-rax-iad-0000805952 devstack@placement-api.service[13847]: ERROR nova.api.openstack.placement.handler 

  Looks like this has at least been around for a week:

  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Unable%20to%20submit%20allocation%20for%20instance%5C%22%20AND%20message%3A%5C%22The%20server%20has%20either%20erred%20or%20is%20incapable%20of%20performing%20the%20requested%20operation%5C%22%20AND%20tags%3A%5C%22screen-n-sch.txt%5C%22&from=10d

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

[Bug 1731668] [NEW] placement: claim allocations fails with IndexError in _ensure_lookup_table_entry
From: Matt Riedemann, 2017-11-11