Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

Volume Creation Issue: Hangs in creating

I've been attempting to create volumes on the block storage node. I've actually had this working once however when I restarted the controller everything went haywire. I've since gone through another complete reinstall to the block storage point and still have this same issue. I've read some of the other posts regarding this but they either haven't been answered or I didn't show a similar issue in the logs. From what I can tell cinder thinks everything went through fine.

Problem: When running the verify sequence "cinder create --display-name demo-volume1 1" subsequently it never creates the volume in the lvm cinder-volumes. It also shows indefinitely as "creating" in the cinder list command. I can manually go into the cinder-volumes volume group and manually create a logical volume within it fine using lvcreate. However cinder seems unable to create the volume itself.

Note: I'm running Centos 7 w/ Openstack Juno


cinder-manage service list (on both controller and storage) Binary Host Zone Status State Updated At cinder-scheduler controller nova enabled :-) 2015-02-07 21:56:33 cinder-volume storage nova enabled :-) 2015-02-07 21:56:32


vgdisplay (on storage) No device found for PV q0T2vH-xdkZ-lVlc-fznp-M3n8-bjC8-rHuT7v. --- Volume group --- VG Name cinder-volumes System ID
Format lvm2 Metadata Areas 1 Metadata Sequence No 3 VG Access read/write VG Status resizable MAX LV 0 Cur LV 2 Open LV 0 Max PV 0 Cur PV 1 Act PV 1 VG Size 36.38 TiB PE Size 4.00 MiB Total PE 9536741 Alloc PE / Size 2 / 8.00 MiB Free PE / Size 9536739 / 36.38 TiB VG UUID XwasvW-gADN-y9Ox-3uyH-hKjI-oGCU-reFD1d


lvdisplay (on storage to show other lv's created, I've manually created these even though they show up in the cinder list) No device found for PV q0T2vH-xdkZ-lVlc-fznp-M3n8-bjC8-rHuT7v. --- Logical volume --- LV Path /dev/cinder-volumes/dem3 LV Name dem3 VG Name cinder-volumes LV UUID Yie3bu-5lek-QxRt-gfjc-BY4Z-qyB2-BoFMIG LV Write Access read/write LV Creation host, time storage, 2015-02-07 16:40:07 -0500 LV Status available # open 0 LV Size 4.00 MiB Current LE 1 Segments 1 Allocation inherit Read ahead sectors auto - currently set to 256 Block device 253:8

--- Logical volume --- LV Path /dev/cinder-volumes/dem LV Name dem VG Name cinder-volumes LV UUID 2cznOu-3Mzj-VlnM-uiMh-ntMV-0flo-FviDTQ LV Write Access read/write LV Creation host, time storage, 2015-02-07 16:41:07 -0500 LV Status available # open 0 LV Size 4.00 MiB Current LE 1 Segments 1 Allocation inherit Read ahead sectors auto - currently set to 256 Block device 253:9


cinder list (on storage and controller, dem2 was seeing what the scheduler would say if the storage node was down) +--------------------------------------+----------+--------------+------+-------------+----------+-------------+ | ID | Status | Display Name | Size | Volume Type | Bootable | Attached to | +--------------------------------------+----------+--------------+------+-------------+----------+-------------+ | 7f947979-77dd-44ca-9da4-24409fdeca82 | creating | demo-volume1 | 1 | None | false | | | 83dc36ab-9a28-4b9d-952b-ca39dc8815b3 | error | dem2 | 1 | None | false | | | bfd3aa9f-9022-4a0f-8c20-4b11380c623d | creating | dem | 1 | None | false | | | d10de795-0ec3-41cb-b048-f3b78bd7ff41 | creating | dem3 | 1 | None | false | | +--------------------------------------+----------+--------------+------+-------------+----------+-------------+


My latest run cinder create --display-name forquestion 2 +---------------------+--------------------------------------+ | Property | Value | +---------------------+--------------------------------------+ | attachments | [] | | availability_zone | nova | | bootable | false | | created_at | 2015-02-07T22:01:33.677857 | | display_description | None | | display_name | forquestion | | encrypted | False | | id | 96c82a50-a96b-41d2-bff6-2be111b214c9 | | metadata | {} | | size | 2 | | snapshot_id | None | | source_volid | None | | status | creating | | volume_type | None |


Log files below

volume.log (storage) 2015-02-07 16:59:47.354 20107 INFO cinder.volume.manager [-] Updating volume status 2015-02-07 16:59:47.354 20107 DEBUG cinder.volume.drivers.lvm [-] Updating volume stats _update_volume_stats /usr/lib/python2.7/site-packages/cinder/volume/drivers/lvm.py:347 2015-02-07 16:59:47.355 20107 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C vgs --noheadings -$ 2015-02-07 16:59:47.442 20107 DEBUG cinder.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/site-packages/cinder/openstack/common/processutils.py:192 2015-02-07 16:59:47.443 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._update_replication_relationship_status run_periodic_tasks /usr/lib$ 2015-02-07 16:59:47.444 20107 INFO cinder.volume.manager [-] Updating volume replication status. 2015-02-07 17:00:47.352 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7$ 2015-02-07 17:00:47.353 20107 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128 2015-02-07 17:00:47.358 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-pa$ 2015-02-07 17:00:47.359 20107 INFO cinder.volume.manager [-] Updating volume status 2015-02-07 17:00:47.359 20107 DEBUG cinder.volume.drivers.lvm [-] Updating volume stats _update_volume_stats /usr/lib/python2.7/site-packages/cinder/volume/drivers/lvm.py:347 2015-02-07 17:00:47.360 20107 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C vgs --noheadings -$ 2015-02-07 17:00:47.457 20107 DEBUG cinder.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/site-packages/cinder/openstack/common/processutils.py:192 2015-02-07 17:00:47.459 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._update_replication_relationship_status run_periodic_tasks /usr/lib$ 2015-02-07 17:00:47.459 20107 INFO cinder.volume.manager [-] Updating volume replication status. 2015-02-07 17:01:47.356 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7$ 2015-02-07 17:01:47.358 20107 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128 2015-02-07 17:01:47.363 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-pa$ 2015-02-07 17:01:47.364 20107 INFO cinder.volume.manager [-] Updating volume status 2015-02-07 17:01:47.365 20107 DEBUG cinder.volume.drivers.lvm [-] Updating volume stats _update_volume_stats /usr/lib/python2.7/site-packages/cinder/volume/drivers/lvm.py:347 2015-02-07 17:01:47.365 20107 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C vgs --noheadings -$ 2015-02-07 17:01:47.465 20107 DEBUG cinder.openstack.common.processutils [-] Result was 0 execute /usr/lib/python2.7/site-packages/cinder/openstack/common/processutils.py:192 2015-02-07 17:01:47.466 20107 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._update_replication_relationship_status run_periodic_tasks /usr/lib$ 2015-02-07 17:01:47.467 20107 INFO cinder.volume.manager [-] Updating volume replication status.

api.log (on controller) 2015-02-07 17:01:33.572 12769 DEBUG cinder.api.v1.volumes [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Create volume request body: {u'volume': {u'status': u'creating', u'user_id': None, u'imageRef': None, u'availability_zone': None, 'scheduler_hints': {}, u'attach_status': u'detached', u'display_description': None, u'metadata': {}, u'source_volid': None, u'snapshot_id': None, u'display_name': u'forquestion', u'project_id': None, u'volume_type': None, u'size': 2}} create /usr/lib/python2.7/site-packages/cinder/api/v1/volumes.py:319 2015-02-07 17:01:33.572 12769 INFO cinder.api.v1.volumes [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Create volume of 2 GB 2015-02-07 17:01:33.578 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Availability zone cache updated, next update will occur around 2015-02-07 23:01:33.578017 list_availability_zones /usr/lib/python2.7/site-packages/cinder/volume/api.py:148 2015-02-07 17:01:33.631 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Translated 'taskflow.patterns.linear_flow.Flow: volume_create_api; 5' into a graph: _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:198 2015-02-07 17:01:33.633 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Name: volume_create_api _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.633 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Type: DiGraph _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.633 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Frozen: False _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.634 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Nodes: 5 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.634 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.634 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.635 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.635 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.635 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.636 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Edges: 4 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.636 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create==1.0 -> cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create==1.0 ({'invariant': True}) _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.636 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create==1.0 -> cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create==1.0 ({'invariant': True}) _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.637 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create==1.0 -> cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create==1.0 ({'invariant': True}) _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.637 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create==1.0 -> cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create==1.0 ({'invariant': True}) _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.638 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Density: 0.200 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.638 12769 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Cycles: 0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.641 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Flow 'volume_create_api' (9058721f-b3cd-42c3-977d-8fa05d78c0c6) transitioned into state 'RUNNING' from state 'PENDING' _flow_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:83 2015-02-07 17:01:33.642 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (ebf9fe43-8347-4f3f-a9bd-835bb4d2385a) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.642 12769 DEBUG cinder.volume.flows.api.create_volume [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Validating volume 2 using validate_int _extract_size /usr/lib/python2.7/site-packages/cinder/volume/flows/api/create_volume.py:218 2015-02-07 17:01:33.644 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (ebf9fe43-8347-4f3f-a9bd-835bb4d2385a) transitioned into state 'SUCCESS' with result '{'volume_type_id': None, 'availability_zone': 'nova', 'source_replicaid': None, 'volume_type': {}, 'qos_specs': None, 'encryption_key_id': None, 'source_volid': None, 'snapshot_id': None, 'consistencygroup_id': None, 'size': 2}' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.644 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create' (94df7ef7-f70a-44e5-826a-f04de4578792) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.672 12769 DEBUG cinder.quota [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Created reservations ['6e43c87e-75d4-49f0-b65b-3e53c2f0d760', '42ca85cd-d375-4630-bf6a-2a00a0f02ef8'] reserve /usr/lib/python2.7/site-packages/cinder/quota.py:761 2015-02-07 17:01:33.672 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create' (94df7ef7-f70a-44e5-826a-f04de4578792) transitioned into state 'SUCCESS' with result '{'reservations': ['6e43c87e-75d4-49f0-b65b-3e53c2f0d760', '42ca85cd-d375-4630-bf6a-2a00a0f02ef8']}' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.673 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create' (001e0d4e-7f93-4378-9e5d-c26b8e62d969) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.708 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create' (001e0d4e-7f93-4378-9e5d-c26b8e62d969) transitioned into state 'SUCCESS' with result '{'volume': <cinder.db.sqlalchemy.models.volume object="" at="" 0x4825590="">, 'volume_properties': {'status': 'creating', 'volume_type_id': None, 'display_name': u'forquestion', 'volume_metadata': [], 'reservations': ['6e43c87e-75d4-49f0-b65b-3e53c2f0d760', '42ca85cd-d375-4630-bf6a-2a00a0f02ef8'], 'display_description': None, 'availability_zone': 'nova', 'attach_status': 'detached', 'source_volid': None, 'metadata': {}, 'source_replicaid': None, 'encryption_key_id': None, 'consistencygroup_id': None, 'replication_status': 'disabled', 'snapshot_id': None, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'project_id': u'8b94649631074479a173ba840d62cb96', 'id': '96c82a50-a96b-41d2-bff6-2be111b214c9', 'size': 2}, 'volume_id': '96c82a50-a96b-41d2-bff6-2be111b214c9'}' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.709 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create' (e41424e5-95d1-4e75-b36c-d7921894a4b5) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.721 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create' (e41424e5-95d1-4e75-b36c-d7921894a4b5) transitioned into state 'SUCCESS' with result '{'volume_properties': {'status': 'creating', 'volume_type_id': None, 'display_name': u'forquestion', 'volume_metadata': [], 'reservations': ['6e43c87e-75d4-49f0-b65b-3e53c2f0d760', '42ca85cd-d375-4630-bf6a-2a00a0f02ef8'], 'display_description': None, 'availability_zone': 'nova', 'attach_status': 'detached', 'source_volid': None, 'metadata': {}, 'source_replicaid': None, 'encryption_key_id': None, 'consistencygroup_id': None, 'replication_status': 'disabled', 'snapshot_id': None, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'project_id': u'8b94649631074479a173ba840d62cb96', 'id': '96c82a50-a96b-41d2-bff6-2be111b214c9', 'size': 2}}' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.722 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create' (6c6e79ba-9be5-4998-a142-c1b521b74264) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.724 12769 INFO oslo.messaging._drivers.impl_rabbit [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Connecting to AMQP server on controller:5672 2015-02-07 17:01:33.744 12769 INFO oslo.messaging._drivers.impl_rabbit [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Connected to AMQP server on controller:5672 2015-02-07 17:01:33.747 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create' (6c6e79ba-9be5-4998-a142-c1b521b74264) transitioned into state 'SUCCESS' with result 'None' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.748 12769 DEBUG cinder.volume.api [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Flow 'volume_create_api' (9058721f-b3cd-42c3-977d-8fa05d78c0c6) transitioned into state 'SUCCESS' from state 'RUNNING' _flow_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:83 2015-02-07 17:01:33.749 12769 INFO cinder.api.v1.volumes [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': 'nova', 'terminated_at': None, 'reservations': ['6e43c87e-75d4-49f0-b65b-3e53c2f0d760', '42ca85cd-d375-4630-bf6a-2a00a0f02ef8'], 'updated_at': None, 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': 'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': '96c82a50-a96b-41d2-bff6-2be111b214c9', 'size': 2, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'source_replicaid': None, 'attached_host': None, 'display_description': None, 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': None, 'status': 'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': None, 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u'forquestion', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 22, 1, 33, 677857), 'attach_status': 'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None, 'metadata': {}} 2015-02-07 17:01:33.753 12769 INFO cinder.api.openstack.wsgi [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] http://controller:8776/v1/8b94649631074479a173ba840d62cb96/volumes returned with HTTP 200 2015-02-07 17:01:33.753 12769 INFO eventlet.wsgi.server [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] 10.0.0.43 - - [07/Feb/2015 17:01:33] "POST /v1/8b94649631074479a173ba840d62cb96/volumes HTTP/1.1" 200 605 0.231623 2015-02-07 17:01:54.154 12767 INFO eventlet.wsgi.server [-] (12767) accepted ('10.0.0.43', 32908) 2015-02-07 17:01:54.156 12767 DEBUG keystoneclient.session [-] REQ: curl -i -X GET http://controller:35357/v3/auth/tokens -H "X-Subject-Token: TOKEN_REDACTED" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: TOKEN_REDACTED" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:155 2015-02-07 17:01:54.202 12767 DEBUG keystoneclient.session [-] RESP: [200] {'x-subject-token': '5051e800288143728cc1a8ba28e3aeb8', 'content-type': 'application/json', 'content-length': '4117', 'vary': 'X-Auth-Token', 'date': 'Sat, 07 Feb 2015 22:01:54 GMT'} RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}], "expires_at": "2015-02-07T23:01:54.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "8b94649631074479a173ba840d62cb96", "name": "demo"}, "catalog": [{"endpoints": [{"region_id": "regionOne", "url": "http://controller:8776/v1/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "internal", "id": "62247b0771de4dd5b40ce17035fb9137"}, {"region_id": "regionOne", "url": "http://controller:8776/v1/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "admin", "id": "67d3a33db23d4efdb12f404de603e47e"}, {"region_id": "regionOne", "url": "http://controller:8776/v1/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "public", "id": "a827f00f767742c7a6ec2e7dba72f30e"}], "type": "volume", "id": "5794d7d3da964cf9bd906ad4c5447852", "name": "cinder"}, {"endpoints": [{"region_id": "regionOne", "url": "http://controller:8774/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "public", "id": "523121308345461d88dfdf58043d7d1c"}, {"region_id": "regionOne", "url": "http://controller:8774/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "internal", "id": "c4369935107a42599b1d2714d07ea79b"}, {"region_id": "regionOne", "url": "http://controller:8774/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "admin", "id": "c7315624ae5549f58922843a9abb1e9a"}], "type": "compute", "id": "85dbe848494442eab8d88c66ac57e118", "name": "nova"}, {"endpoints": [{"region_id": "regionOne", "url": "http://controller:9696", "region": "regionOne", "interface": "internal", "id": "345f4431b0fe43ebba4914dfb55c899a"}, {"region_id": "regionOne", "url": "http://controller:9696", "region": "regionOne", "interface": "public", "id": "949de4754eb54335813aae204bdd12fa"}, {"region_id": "regionOne", "url": "http://controller:9696", "region": "regionOne", "interface": "admin", "id": "b1e2a01f520443ada7ea53cedc828d9e"}], "type": "network", "id": "8805666e019a4611be7c8facb20570cb", "name": "neutron"}, {"endpoints": [{"region_id": "regionOne", "url": "http://controller:9292", "region": "regionOne", "interface": "public", "id": "0f72b78fbb074c449c7a8e7a291152b7"}, {"region_id": "regionOne", "url": "http://controller:9292", "region": "regionOne", "interface": "admin", "id": "6790e5ee34b8416298b951640d26f2ce"}, {"region_id": "regionOne", "url": "http://controller:9292", "region": "regionOne", "interface": "internal", "id": "fea9874ea1fe4e6abd426e81e44f1f58"}], "type": "image", "id": "a886f6101b09492bbd5a195ea597ad93", "name": "glance"}, {"endpoints": [{"region_id": "regionOne", "url": "http://controller:5000/v2.0", "region": "regionOne", "interface": "public", "id": "3cb8ce5414744b80be130552ddd2d1cb"}, {"region_id": "regionOne", "url": "http://controller:5000/v2.0", "region": "regionOne", "interface": "internal", "id": "94a95f92babc4d2d899eaf75b26393fd"}, {"region_id": "regionOne", "url": "http://controller:35357/v2.0", "region": "regionOne", "interface": "admin", "id": "dab1dd63c0704e8281c54ac2c319b0ce"}], "type": "identity", "id": "d7aa5ed11fb349729020798606045be3", "name": "keystone"}, {"endpoints": [{"region_id": "regionOne", "url": "http://controller:8776/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "admin", "id": "701d95dd8f8c42f0beefa213fdf83c65"}, {"region_id": "regionOne", "url": "http://controller:8776/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "public", "id": "85b7b98cab1f45cfbc2c7073251487bb"}, {"region_id": "regionOne", "url": "http://controller:8776/v2/8b94649631074479a173ba840d62cb96", "region": "regionOne", "interface": "internal", "id": "eff18eb771dd467fa2ef11ae393327cd"}], "type": "volumev2", "id": "f91a87eeb94e4366b725a0032113bdb1", "name": "cinderv2"}], "extras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "3dc91645df8c417a8615657f9e65f354", "name": "demo"}, "audit_ids": ["KTGOXV-6Q0Wsn0Sm7IxYDw"], "issued_at": "2015-02-07T22:01:54.145770"}} _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:182 2015-02-07 17:01:54.204 12767 INFO cinder.api.openstack.wsgi [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] GET http://controller:8776/v1/8b94649631074479a173ba840d62cb96/volumes/detail 2015-02-07 17:01:54.204 12767 DEBUG cinder.api.openstack.wsgi [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Empty body provided in request get_body /usr/lib/python2.7/site-packages/cinder/api/openstack/wsgi.py:789 2015-02-07 17:01:54.205 12767 DEBUG cinder.utils [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Removing options '' from query. remove_invalid_filter_options /usr/lib/python2.7/site-packages/cinder/utils.py:757 2015-02-07 17:01:54.205 12767 DEBUG cinder.volume.api [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Searching by: MultiDict([('no_migration_targets', True)]) get_all /usr/lib/python2.7/site-packages/cinder/volume/api.py:384 2015-02-07 17:01:54.229 12767 INFO cinder.api.v1.volumes [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2015, 2, 7, 22, 1, 33), 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'96c82a50-a96b-41d2-bff6-2be111b214c9', 'size': 2L, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': [], 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': datetime.datetime(2015, 2, 7, 22, 1, 33), 'status': u'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': u'storage#LVM_iSCSI', 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u'forquestion', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 22, 1, 33), 'attach_status': u'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None} 2015-02-07 17:01:54.233 12767 INFO cinder.api.v1.volumes [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2015, 2, 7, 21, 37, 22), 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'd10de795-0ec3-41cb-b048-f3b78bd7ff41', 'size': 1L, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': [], 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': datetime.datetime(2015, 2, 7, 21, 37, 22), 'status': u'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': u'storage#LVM_iSCSI', 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u'dem3', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 21, 37, 21), 'attach_status': u'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None} 2015-02-07 17:01:54.237 12767 INFO cinder.api.v1.volumes [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2015, 2, 7, 21, 8, 19), 'provider_geometry': None, 'replication_extended_status': None, 'replication_statu s': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'83dc36ab-9a28-4b9d-952b-ca39dc8815b3', 'size': 1L, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': [], 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': Non e, 'status': u'error', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': None, 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u 'dem2', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 21, 8, 19), 'attach_status': u'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metada ta': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None} 2015-02-07 17:01:54.241 12767 INFO cinder.api.v1.volumes [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2015, 2, 7, 21, 3, 31), 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'bfd3aa9f-9022-4a0f-8c20-4b11380c623d', 'size': 1L, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': [], 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': datetime.datetime(2015, 2, 7, 21, 3, 31), 'status': u'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': u'storage#LVM_iSCSI', 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u'dem', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 21, 3, 31), 'attach_status': u'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None} 2015-02-07 17:01:54.245 12767 INFO cinder.api.v1.volumes [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2015, 2, 7, 20, 1, 13), 'provider_geometry': None, 'replication_extended_status': None, 'replication_status': u'disabled', 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': u'7f947979-77dd-44ca-9da4-24409fdeca82', 'size': 1L, 'user_id': u'3dc91645df8c417a8615657f9e65f354', 'attach_time': None, 'attached_host': None, 'display_description': None, 'volume_admin_metadata': [], 'project_id': u'8b94649631074479a173ba840d62cb96', 'launched_at': None, 'scheduled_at': datetime.datetime(2015, 2, 7, 20, 1, 12), 'status': u'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': u'storage#LVM_iSCSI', 'consistencygroup_id': None, 'source_volid': None, 'provider_auth': None, 'display_name': u'demo-volume1', 'instance_uuid': None, 'bootable': False, 'created_at': datetime.datetime(2015, 2, 7, 20, 1, 12), 'attach_status': u'detached', 'volume_type': None, 'consistencygroup': None, 'volume_metadata': [], '_name_id': None, 'encryption_key_id': None, 'replication_driver_data': None} 2015-02-07 17:01:54.254 12767 INFO cinder.api.openstack.wsgi [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] http://controller:8776/v1/8b94649631074479a173ba840d62cb96/volumes/detail returned with HTTP 200 2015-02-07 17:01:54.255 12767 INFO eventlet.wsgi.server [req-55c5e6a7-f2c2-422b-954f-193fe8046539 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] 10.0.0.43 - - [07/Feb/2015 17:01:54] "GET /v1/8b94649631074479a173ba840d62cb96/volumes/detail HTTP/1.1" 200 2799 0.099629

Scheduler.log (from controller) 2015-02-07 17:01:33.749 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Translated 'taskflow.patterns.linear_flow.Flow: volume_create_scheduler; 2' into a graph: _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:198 2015-02-07 17:01:33.750 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Name: volume_create_scheduler _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.751 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Type: DiGraph _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.751 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Frozen: False _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.751 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Nodes: 2 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.752 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.752 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] - cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create==1.0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.752 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Edges: 1 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.753 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create==1.0 -> cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create==1.0 ({'invariant': True}) _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.753 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Density: 0.500 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.753 12749 DEBUG taskflow.engines.action_engine.compiler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Cycles: 0 _post_flatten /usr/lib/python2.7/site-packages/taskflow/engines/action_engine/compiler.py:201 2015-02-07 17:01:33.755 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Flow 'volume_create_scheduler' (6d08a62c-09a7-43b5-b3e8-1861cce5e9ac) transitioned into state 'RUNNING' from state 'PENDING' _flow_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:83 2015-02-07 17:01:33.756 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' (bb20f605-087a-4432-b8cd-358c6f0ea656) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.757 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' (bb20f605-087a-4432-b8cd-358c6f0ea656) transitioned into state 'SUCCESS' with result '{'request_spec': {u'source_replicaid': None, u'volume_properties': {u'status': u'creating', u'volume_type_id': None, u'display_name': u'forquestion', u'availability_zone': u'nova', u'reservations': [u'6e43c87e-75d4-49f0-b65b-3e53c2f0d760', u'42ca85cd-d375-4630-bf6a-2a00a0f02ef8'], u'attach_status': u'detached', u'display_description': None, u'id': u'96c82a50-a96b-41d2-bff6-2be111b214c9', u'metadata': {}, u'source_replicaid': None, u'encryption_key_id': None, u'volume_metadata': [], u'replication_status': u'disabled', u'snapshot_id': None, u'source_volid': None, u'user_id': u'3dc91645df8c417a8615657f9e65f354', u'project_id': u'8b94649631074479a173ba840d62cb96', u'consistencygroup_id': None, u'size': 2}, u'volume_type': {}, u'image_id': None, u'snapshot_id': None, u'consistencygroup_id': None, u'source_volid': None, u'volume_id': u'96c82a50-a96b-41d2-bff6-2be111b214c9'}}' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.757 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (8bf1278d-9257-4fb5-9830-44e8cff878a8) transitioned into state 'RUNNING' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:131 2015-02-07 17:01:33.762 12749 DEBUG cinder.scheduler.filters.capacity_filter [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Sufficient free space for volume creation on host storage#LVM_iSCSI (requested / avail): 2/37252.0 host_passes /usr/lib/python2.7/site-packages/cinder/scheduler/filters/capacity_filter.py:68 2015-02-07 17:01:33.763 12749 DEBUG cinder.scheduler.filter_scheduler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Filtered [host 'storage#LVM_iSCSI': free_capacity_gb: 37252.89, pools: None] _get_weighted_candidates /usr/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py:300 2015-02-07 17:01:33.763 12749 DEBUG cinder.scheduler.filter_scheduler [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Choosing storage#LVM_iSCSI _choose_top_host /usr/lib/python2.7/site-packages/cinder/scheduler/filter_scheduler.py:419 2015-02-07 17:01:33.796 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (8bf1278d-9257-4fb5-9830-44e8cff878a8) transitioned into state 'SUCCESS' with result 'None' _task_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:113 2015-02-07 17:01:33.797 12749 DEBUG cinder.scheduler.manager [req-f9100f1d-3487-40ef-a988-bdb50c589a51 3dc91645df8c417a8615657f9e65f354 8b94649631074479a173ba840d62cb96 - - -] Flow 'volume_create_scheduler' (6d08a62c-09a7-43b5-b3e8-1861cce5e9ac) transitioned into state 'SUCCESS' from state 'RUNNING' _flow_receiver /usr/lib/python2.7/site-packages/cinder/flow_utils.py:83