select_destinations results in "TypeError: 'NoneType' object is not iterable" if get_allocation_candidates fails to connect to Placement

[Matt Riedemann]

http://logs.openstack.org/99/471899/25/check/gate-grenade-dsvm-neutron-ubuntu-xenial/3f9a9e3/logs/new/screen-n-cond.txt.gz?level=TRACE#_2017-07-18_22_04_39_026

2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager Traceback (most recent call last):
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/conductor/manager.py", line 920, in schedule_and_build_instances
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager instance_uuids)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/conductor/manager.py", line 624, in _schedule_instances
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager request_spec, instance_uuids)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/utils.py", line 464, in wrapped
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager return func(*args, **kwargs)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/client/__init__.py", line 52, in select_destinations
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager instance_uuids)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/client/__init__.py", line 37, in __run_method
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager return getattr(self.instance, __name)(*args, **kwargs)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/client/query.py", line 33, in select_destinations
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager instance_uuids)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/rpcapi.py", line 136, in select_destinations
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager return cctxt.call(ctxt, 'select_destinations', **msg_args)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 169, in call
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager retry=self.retry)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 123, in _send
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager timeout=timeout, retry=retry)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 578, in send
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager retry=retry)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 569, in _send
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager raise result
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager TypeError: 'NoneType' object is not iterable
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager Traceback (most recent call last):
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 153, in _process_incoming
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager res = self.dispatcher.dispatch(message)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 213, in dispatch
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager return self._do_dispatch(endpoint, method, ctxt, args)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _do_dispatch
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager result = func(ctxt, **new_args)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 225, in inner
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager return func(*args, **kwargs)
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager File "/opt/stack/new/nova/nova/scheduler/manager.py", line 114, in select_destinations
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager alloc_reqs, p_sums = res
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager TypeError: 'NoneType' object is not iterable
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager
2017-07-18 22:04:39.026 32126 ERROR nova.conductor.manager

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22in%20select_destinations%5C%22%20AND%20message%3A%5C%22alloc_reqs%2C%20p_sums%20%3D%20res%5C%22%20AND%20message%3A%5C%22TypeError%3A%20'NoneType'%20object%20is%20not%20iterable%5C%22%20AND%20tags%3A%5C%22screen-n-cond.txt%5C%22&from=7d

[Matt Riedemann (mriedem)]

This is during a grenade run. It looks like this could maybe happen if the safe_connect decorator handles a keystone endpoint/auth failure and returns None.

[Matt Riedemann (mriedem)]

Yup that's exactly what happened:

http://logs.openstack.org/99/471899/25/check/gate-grenade-dsvm-neutron-ubuntu-xenial/3f9a9e3/logs/new/screen-n-sch.txt.gz#_2017-07-18_22_04_39_022

2017-07-18 22:04:39.022 31224 WARNING nova.scheduler.client.report [req-4d9d9061-72b6-414b-a759-e89eeaa1c24c tempest-ServersTestManualDisk-1849630423 tempest-ServersTestManualDisk-1849630423] Placement API service is not responding.: ConnectFailure: Unable to establish connection to http://10.0.1.195/placement/allocation_candidates?resources=MEMORY_MB%3A64%2CVCPU%3A1: ('Connection aborted.', BadStatusLine("''",))
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server [req-4d9d9061-72b6-414b-a759-e89eeaa1c24c tempest-ServersTestManualDisk-1849630423 tempest-ServersTestManualDisk-1849630423] Exception during message handling: TypeError: 'NoneType' object is not iterable
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 153, in _process_incoming
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 213, in dispatch
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _do_dispatch
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 225, in inner
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server return func(*args, **kwargs)
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server File "/opt/stack/new/nova/nova/scheduler/manager.py", line 114, in select_destinations
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server alloc_reqs, p_sums = res
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server TypeError: 'NoneType' object is not iterable
2017-07-18 22:04:39.022 31224 ERROR oslo_messaging.rpc.server

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/484988

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/484988
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=dcde535f957e2eb4b8bfddd48d6f19eef05ad4f9
Submitter: Jenkins
Branch: master

commit dcde535f957e2eb4b8bfddd48d6f19eef05ad4f9
Author: Matt Riedemann <email address hidden>
Date: Tue Jul 18 20:08:57 2017 -0400

    Handle None returned from get_allocation_candidates due to connect failure

    The get_allocation_candidates method is decorated with the safe_connect
    decorator that handles any failures trying to connect to the Placement
    service. If keystoneauth raises an exception, safe_connect will log it
    and return None. The select_destinations() method in the SchedulerManager
    needs to handle the None case so it doesn't assume a tuple is coming back
    which would result in a TypeError.

    Change-Id: Iffd72f51f25a9e874eaacf374d80794675236ac1
    Closes-Bug: #1705141

[OpenStack Infra (hudson-openstack)]

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