cinder scheduler traceback on volume create

Bug #1619739 reported by Serguei Bezverkhi
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
New
Undecided
Unassigned

Bug Description

when creating a volume in k8s environment, scheduler log shows several tracebacks and volume creation fails.
No errors are seen in cinder api or cinder volume logs.

2016-09-02 12:45:21.622 1 INFO cinder.service [-] Starting cinder-scheduler node (version 9.0.0)
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit [-] Failed to process message ... skipping it.
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit Traceback (most recent call last):
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 337, in _callback
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit self.callback(RabbitMessage(message))
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 190, in __call__
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit unique_id = self.msg_id_cache.check_duplicate_message(message)
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/_drivers/amqp.py", line 121, in check_duplicate_message
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit raise rpc_common.DuplicateMessageError(msg_id=msg_id)
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit DuplicateMessageError: Found duplicate message(14ffb5ee979e400482033fb5faf3212d). Skipping it.
2016-09-02 12:46:52.347 1 ERROR oslo.messaging._drivers.impl_rabbit
2016-09-02 12:47:46.164 1 ERROR cinder.scheduler.flows.create_volume [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Failed to run task cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create: 'NoneType' object has no attribute 'get'
2016-09-02 12:47:46.353 1 WARNING cinder.scheduler.manager [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (ca70a750-0dbe-47b7-b8d2-5aa2b0405097) transitioned into state 'FAILURE' from state 'RUNNING'
2 predecessors (most recent first):
  Atom 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2016-09-02T16:47:45Z,deleted=False,deleted_at=None,display_description=None,display_name='first-ever-volume-on-k8s',ec2_id=None,encryption_key_id=None,glance_metadata={},group=<?>,group_id=None,host=None,id=d2297fb3-f67f-451e-8bfb-4d4475908590,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='f738285a670c4be08d8a5e300aa25504',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status='disabled',scheduled_at=None,size=10,snapshot_id=None,snapshots=<?>,source_volid=None,status='error',terminated_at=None,updated_at=None,user_id='3d1cd826f71a49cc81b33e85329f94b3',volume_attachment=<?>,volume_type=<?>,volume_type_id=None), 'image_id': None, 'request_spec': RequestSpec(CG_backend=<?>,cgsnapshot_id=None,consistencygroup_id=None,group_backend=<?>,group_id=None,image_id=None,snapshot_id=None,source_replicaid=None,source_volid=None,volume=Volume(d2297fb3-f67f-451e-8bfb-4d4475908590),volume_id=d2297fb3-f67f-451e-8bfb-4d4475908590,volume_properties=VolumeProperties,volume_type=None), 'context': <cinder.context.RequestContext object at 0x66f2610>, 'snapshot_id': None}, 'provides': {'request_spec': RequestSpec(CG_backend=<?>,cgsnapshot_id=None,consistencygroup_id=None,group_backend=<?>,group_id=None,image_id=None,snapshot_id=None,source_replicaid=None,source_volid=None,volume=Volume(d2297fb3-f67f-451e-8bfb-4d4475908590),volume_id=d2297fb3-f67f-451e-8bfb-4d4475908590,volume_properties=VolumeProperties,volume_type=None)}}
  |__Flow 'volume_create_scheduler'
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager Traceback (most recent call last):
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager result = task.execute(**arguments)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/flows/create_volume.py", line 144, in execute
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager common.error_out(volume, reason=e)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager self.force_reraise()
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager six.reraise(self.type_, self.value, self.tb)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/flows/create_volume.py", line 126, in execute
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager filter_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 108, in schedule_create_volume
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager filter_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 607, in _schedule
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager filter_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 337, in _get_weighted_candidates
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager filter_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/host_manager.py", line 432, in get_weighed_hosts
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager weight_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/base_weight.py", line 134, in get_weighed_objects
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager weights = weigher.weigh_objects(weighed_objs, weighing_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/weights/capacity.py", line 88, in weigh_objects
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager weighed_obj_list, weight_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/base_weight.py", line 102, in weigh_objects
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager weight = self._weigh_object(obj.obj, weight_properties)
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/weights/capacity.py", line 123, in _weigh_object
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager provision_type = vol_type.get('extra_specs', {}).get(
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager AttributeError: 'NoneType' object has no attribute 'get'
2016-09-02 12:47:46.353 1 ERROR cinder.scheduler.manager
2016-09-02 12:47:46.361 1 WARNING cinder.scheduler.manager [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (ca70a750-0dbe-47b7-b8d2-5aa2b0405097) transitioned into state 'REVERTED' from state 'REVERTING'
2016-09-02 12:47:46.365 1 WARNING cinder.scheduler.manager [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Task 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' (137ab547-a33e-4961-ad27-d5403b84c3b6) transitioned into state 'REVERTED' from state 'REVERTING'
2016-09-02 12:47:46.368 1 WARNING cinder.scheduler.manager [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Flow 'volume_create_scheduler' (6a3d6330-acfb-4e49-a72c-0ee5f557a275) transitioned into state 'REVERTED' from state 'RUNNING'
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server [req-45a7d869-dfde-4e83-9401-95f2b48c0bec 3d1cd826f71a49cc81b33e85329f94b3 f738285a670c4be08d8a5e300aa25504 - default default] Exception during message handling
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/manager.py", line 187, in create_volume
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server flow_engine.run()
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 247, in run
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server for _state in self.run_iter(timeout=timeout):
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 340, in run_iter
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server failure.Failure.reraise_if_any(er_failures)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/types/failure.py", line 336, in reraise_if_any
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server failures[0].reraise()
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/types/failure.py", line 343, in reraise
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server six.reraise(*self._exc_info)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server result = task.execute(**arguments)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/flows/create_volume.py", line 144, in execute
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server common.error_out(volume, reason=e)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/flows/create_volume.py", line 126, in execute
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server filter_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 108, in schedule_create_volume
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server filter_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 607, in _schedule
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server filter_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py", line 337, in _get_weighted_candidates
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server filter_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/host_manager.py", line 432, in get_weighed_hosts
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server weight_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/base_weight.py", line 134, in get_weighed_objects
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server weights = weigher.weigh_objects(weighed_objs, weighing_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/weights/capacity.py", line 88, in weigh_objects
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server weighed_obj_list, weight_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/base_weight.py", line 102, in weigh_objects
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server weight = self._weigh_object(obj.obj, weight_properties)
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server File "/var/lib/kolla/venv/lib/python2.7/site-packages/cinder/scheduler/weights/capacity.py", line 123, in _weigh_object
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server provision_type = vol_type.get('extra_specs', {}).get(
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server AttributeError: 'NoneType' object has no attribute 'get'
2016-09-02 12:47:46.369 1 ERROR oslo_messaging.rpc.server

Revision history for this message
Eric Harney (eharney) wrote :

The error at the bottom is bug 1619246 and should be fixed now.

Revision history for this message
Michal Dulko (michal-dulko-f) wrote :

Yup, so Kolla doesn't create a default volume type if I recall correctly. This is definitely bug 1619246 which is already fixed.

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

Other bug subscribers

Remote bug watches

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