I have a very by-the-book new Rocky deployment with one Controller code and 2 Compute+Block Storage nodes. Everything seems to be working fine; I can launch basic VMs, create images, and create empty volumes without issue. BUT when I try to launch a new VM from an Image (or try to create a volume from an image) I get the follow;
In the controller's cinder-scheduler.log:
2019-06-18 20:00:39.607 3189 ERROR cinder.scheduler.filter_scheduler [req-71dd7b62-2136-4e9e-8acf-c4e93efcd51f 635c8bde2ff84af7ab73f626cfb44869 584d29866c31481e9dd3d7fd81ab9a9f - e8704477966d46e7831d202cec8bc815 e8704477966d46e7831d202cec8bc815] Error scheduling 94af426e-d2e0-48d1-87e9-7911c0f2b2ca from last vol-service: ott-openstack-cpu1@LVM-HDD#LVM-HDD : [u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.7/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task\n result = task.execute(**arguments)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/volume/flows/manager/create_volume.py", line 312, in execute\n image_id),\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 315, in get_location\n _reraise_translated_image_exception(image_id)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 602, in _reraise_translated_image_exception\n six.reraise(type(new_exc), new_exc, exc_trace)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 313, in get_location\n image_meta = client.call(context, \'get\', image_id)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 221, in call\n client = self.client or self._create_onetime_client(context)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 206, in _create_onetime_client\n self.use_ssl)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 128, in _create_glance_client\n _SESSION = ks_session.Session().load_from_options(**config_options)\n', u' File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/session.py", line 77, in load_from_options\n **kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/base.py", line 164, in load_from_options\n return self.create_plugin(**kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/base.py", line 125, in create_plugin\n return self.plugin_class(**kwargs)\n', u"TypeError: __init__() got an unexpected keyword argument 'split_loggers'\n"]
2019-06-18 20:00:39.608 3189 INFO cinder.message.api [req-71dd7b62-2136-4e9e-8acf-c4e93efcd51f 635c8bde2ff84af7ab73f626cfb44869 584d29866c31481e9dd3d7fd81ab9a9f - e8704477966d46e7831d202cec8bc815 e8704477966d46e7831d202cec8bc815] Creating message record for request_id = req-71dd7b62-2136-4e9e-8acf-c4e93efcd51f
2019-06-18 20:00:39.710 3189 ERROR cinder.scheduler.flows.create_volume [req-71dd7b62-2136-4e9e-8acf-c4e93efcd51f 635c8bde2ff84af7ab73f626cfb44869 584d29866c31481e9dd3d7fd81ab9a9f - e8704477966d46e7831d202cec8bc815 e8704477966d46e7831d202cec8bc815] Failed to run task cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create: No valid backend was found. Exceeded max scheduling attempts 3 for resource 94af426e-d2e0-48d1-87e9-7911c0f2b2ca: NoValidBackend: No valid backend was found. Exceeded max scheduling attempts 3 for resource 94af426e-d2e0-48d1-87e9-7911c0f2b2ca
and in the compute/storage node's cinder-volume.log;
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server [req-71dd7b62-2136-4e9e-8acf-c4e93efcd51f 635c8bde2ff84af7ab73f626cfb44869 584d29866c31481e9dd3d7fd81ab9a9f - e8704477966d46e7831d202cec8bc815 e8704477966d46e7831d202cec8bc815] Exception during message handling: TypeError: __init__() got an unexpected keyword argument 'split_loggers'
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server 'interval': cm_heartbeat_interval}))
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server new_args = dict()
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "<decorator-gen-239>", line 2, in create_volume
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/objects/cleanable.py", line 207, in wrapper
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server result = f(*args, **kwargs)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 666, in create_volume
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server _run_flow()
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 658, in _run_flow
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server flow_engine.run()
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/taskflow/engines/action_engine/engine.py", line 247, in run
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server for _state in self.run_iter(timeout=timeout):
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/taskflow/engines/action_engine/engine.py", line 340, in run_iter
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server failure.Failure.reraise_if_any(er_failures)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/taskflow/types/failure.py", line 336, in reraise_if_any
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server failures[0].reraise()
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/taskflow/types/failure.py", line 343, in reraise
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server six.reraise(*self._exc_info)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server result = task.execute(**arguments)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/volume/flows/manager/create_volume.py", line 312, in execute
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server image_id),
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 315, in get_location
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server _reraise_translated_image_exception(image_id)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 602, in _reraise_translated_image_exception
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server six.reraise(type(new_exc), new_exc, exc_trace)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 313, in get_location
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server image_meta = client.call(context, 'get', image_id)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 221, in call
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server client = self.client or self._create_onetime_client(context)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 206, in _create_onetime_client
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server self.use_ssl)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/cinder/image/glance.py", line 128, in _create_glance_client
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server _SESSION = ks_session.Session().load_from_options(**config_options)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/session.py", line 77, in load_from_options
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server **kwargs)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/base.py", line 164, in load_from_options
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server return self.create_plugin(**kwargs)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/keystoneauth1/loading/base.py", line 125, in create_plugin
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server return self.plugin_class(**kwargs)
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server TypeError: __init__() got an unexpected keyword argument 'split_loggers'
2019-06-18 20:00:39.788 2907 ERROR oslo_messaging.rpc.server