O063、NFS Volume Provider（Part II）

参考https://www.cnblogs.com/CloudMan6/p/5693771.html

 

本节开始创建 NFS volume ，操作方法和 LVM volume一样，唯一的区别是在 volume type 的下拉列表中选择 nfs

 

 

 

 

[root@FTP ~]# ll /home/nfs1/

total 0

-rw-rw-rw-. 1 root root 1073741824 Jul  3 22:03 volume-07acd9e8-def4-434a-8657-d6c257929b67

 

[root@DevStack-Rocky-Controller-21 ~]# ll /nfs_storage/cc6a13e63509492ab709bb63b536feed/

total 0

-rw-rw-rw-. 1 root root 1073741824 Jul  3 22:03 volume-07acd9e8-def4-434a-8657-d6c257929b67

 

[root@DevStack-Rocky-Compute-22 ~]# ll /nfs_storage/cc6a13e63509492ab709bb63b536feed/

total 0

-rw-rw-rw-. 1 root root 1073741824 Jul  3 22:03 volume-07acd9e8-def4-434a-8657-d6c257929b67

 

 

cinder-volume 会启动Flow来完成volume创建工作，Flow的名称为： volume_create_manager

 

volume_create_manager 首先执行 ExtractVolumeRefTask、 OnFailureRescheduleTask、 ExtractVolumeSpecTask、 NotifyVolumeActionTask、为volume创建做准备。然后由CreateVolumeFromSpecTask真正创建volume

 

1、mount 远程NFS目录

2、执行 stat、du命令检查NFS目录

3、执行truncate创建volume文件

4、设置volume文件为可读可写

 

最后执行CreateVolumeOnFinishTask完成收尾工作

 

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] POST http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Action: 'create', calling method: create, body: {"volume": {"backup_id": null, "description": "", "multiattach": false, "source_volid": null, "consistencygroup_id": null, "snapshot_id": null, "size": 1, "name": "nfs-vol-xx", "imageRef": null, "availability_zone": "nova", "volume_type": "nfs", "metadata": {}}} {{(pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:869}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.v3.volumes [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Create volume request body: {u'volume': {u'backup_id': None, u'description': u'', u'imageRef': None, u'multiattach': False, u'availability_zone': u'nova', u'source_volid': None, u'name': u'nfs-vol-xx', u'consistencygroup_id': None, u'volume_type': u'nfs', u'snapshot_id': None, u'metadata': {}, u'size': 1}} {{(pid=21070) create /opt/stack/cinder/cinder/api/v3/volumes.py:252}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.v3.volumes [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Create volume of 1 GB

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Availability Zones retrieved successfully.

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Flow 'volume_create_api' (08cb0891-b0d0-432d-9061-044338d0e34d) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (a84bd3bd-b25d-4aec-962e-f74104df6101) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.flows.api.create_volume [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Validating volume size '1' using validate_int {{(pid=21070) _extract_size /opt/stack/cinder/cinder/volume/flows/api/create_volume.py:209}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.ExtractVolumeRequestTask;volume:create' (a84bd3bd-b25d-4aec-962e-f74104df6101) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'volume_type_id': u'68c3bab8-d6cd-4add-823e-56383b4e0f3e', 'backup_id': None, 'multiattach': False, 'refresh_az': False, 'source_volid': None, 'qos_specs': None, 'consistencygroup_id': None, 'replication_status': 'disabled', 'snapshot_id': None, 'size': 1, 'availability_zones': [u'nova'], 'volume_type': VolumeType(created_at=2019-07-03T12:19:12Z,deleted=False,deleted_at=None,description='',extra_specs={volume_backend_name='nfs'},id=68c3bab8-d6cd-4add-823e-56383b4e0f3e,is_public=True,name='nfs',projects=[],qos_specs=<?>,qos_specs_id=None,updated_at=None), 'cgsnapshot_id': None, 'encryption_key_id': None, 'group_id': None}' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:26 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create' (e319a316-993a-4397-a26e-a252e0e9eba0) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.quota [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Created reservations ['cf93bf56-359e-4632-8547-b994d764570f', '7e37b948-2ce9-4b1a-8ab6-4c1f5edb3cc0', '1187be03-4319-41d5-977a-e7794c293d74', '73037e84-a96a-45fd-9d8b-60e109f6ceaa'] {{(pid=21070) reserve /opt/stack/cinder/cinder/quota.py:1029}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.QuotaReserveTask;volume:create' (e319a316-993a-4397-a26e-a252e0e9eba0) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'reservations': ['cf93bf56-359e-4632-8547-b994d764570f', '7e37b948-2ce9-4b1a-8ab6-4c1f5edb3cc0', '1187be03-4319-41d5-977a-e7794c293d74', '73037e84-a96a-45fd-9d8b-60e109f6ceaa']}' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create' (4f212daf-b833-492f-bb69-5e4d0e85ad66) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.EntryCreateTask;volume:create' (4f212daf-b833-492f-bb69-5e4d0e85ad66) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'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=2019-07-03T14:05:27Z,deleted=False,deleted_at=None,display_description='',display_name='nfs-vol-xx',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host=None,id=07acd9e8-def4-434a-8657-d6c257929b67,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='9ed27f1df9814f91b370d1003b066b0a',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=None,service_uuid=None,shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='creating',terminated_at=None,updated_at=None,user_id='0acd431e550c4309be26a1c52e684605',volume_attachment=<?>,volume_type=<?>,volume_type_id=68c3bab8-d6cd-4add-823e-56383b4e0f3e), 'volume_properties': VolumeProperties(attach_status='detached',availability_zone='nova',cgsnapshot_id=None,consistencygroup_id=None,display_description='',display_name='nfs-vol-xx',encryption_key_id=None,group_id=None,group_type_id=<?>,metadata={},multiattach=False,project_id='9ed27f1df9814f91b370d1003b066b0a',qos_specs=None,replication_status=<?>,reservations=['cf93bf56-359e-4632-8547-b994d764570f','7e37b948-2ce9-4b1a-8ab6-4c1f5edb3cc0','1187be03-4319-41d5-977a-e7794c293d74','73037e84-a96a-45fd-9d8b-60e109f6ceaa'],size=1,snapshot_id=None,source_replicaid=<?>,source_volid=None,status='creating',user_id='0acd431e550c4309be26a1c52e684605',volume_type_id=68c3bab8-d6cd-4add-823e-56383b4e0f3e), 'volume_id': '07acd9e8-def4-434a-8657-d6c257929b67'}' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create' (725cd787-c8ca-41e6-b6d2-31d8f15ddd0d) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.QuotaCommitTask;volume:create' (725cd787-c8ca-41e6-b6d2-31d8f15ddd0d) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'volume_properties': VolumeProperties(attach_status='detached',availability_zone='nova',cgsnapshot_id=None,consistencygroup_id=None,display_description='',display_name='nfs-vol-xx',encryption_key_id=None,group_id=None,group_type_id=<?>,metadata={},multiattach=False,project_id='9ed27f1df9814f91b370d1003b066b0a',qos_specs=None,replication_status=<?>,reservations=['cf93bf56-359e-4632-8547-b994d764570f','7e37b948-2ce9-4b1a-8ab6-4c1f5edb3cc0','1187be03-4319-41d5-977a-e7794c293d74','73037e84-a96a-45fd-9d8b-60e109f6ceaa'],size=1,snapshot_id=None,source_replicaid=<?>,source_volid=None,status='creating',user_id='0acd431e550c4309be26a1c52e684605',volume_type_id=68c3bab8-d6cd-4add-823e-56383b4e0f3e)}' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create' (c92ec20a-87d1-4075-b39c-b321a1c71d7c) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Task 'cinder.volume.flows.api.create_volume.VolumeCastTask;volume:create' (c92ec20a-87d1-4075-b39c-b321a1c71d7c) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=21070) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Flow 'volume_create_api' (08cb0891-b0d0-432d-9061-044338d0e34d) transitioned into state 'SUCCESS' from state 'RUNNING' {{(pid=21070) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Flow 'volume_create_scheduler' (2947b22f-db94-42b0-b747-34abcc8eb146) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21820) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' (f730daa2-bc1c-409c-ad68-47ec97e3ccda) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21820) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.scheduler.flows.create_volume.ExtractSchedulerSpecTask;volume:create' (f730daa2-bc1c-409c-ad68-47ec97e3ccda) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'request_spec': RequestSpec(CG_backend=<?>,availability_zones=['nova'],backup_id=None,cgsnapshot_id=None,consistencygroup_id=None,group_backend=<?>,group_id=None,image_id=None,operation='create_volume',resource_backend=<?>,snapshot_id=None,source_replicaid=<?>,source_volid=None,volume=Volume(07acd9e8-def4-434a-8657-d6c257929b67),volume_id=07acd9e8-def4-434a-8657-d6c257929b67,volume_properties=VolumeProperties,volume_type=VolumeType(68c3bab8-d6cd-4add-823e-56383b4e0f3e))}' {{(pid=21820) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (2095b82b-32ed-4829-aee4-6450ca7473be) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=21820) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG oslo_db.sqlalchemy.engines [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION {{(pid=21820) _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:308}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.volume.api [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Create volume request issued successfully.

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Updating capabilities for DevStack-Rocky-Controller-21@lvmdriver-1#lvmdriver-1: {u'pool_name': u'lvmdriver-1', u'filter_function': None, u'goodness_function': None, u'multiattach': True, u'total_volumes': 4, u'provisioned_capacity_gb': 3.0, 'timestamp': datetime.datetime(2019, 7, 3, 14, 5, 1, 623563), u'allocated_capacity_gb': 2, 'volume_backend_name': u'lvmdriver-1', u'thin_provisioning_support': True, u'free_capacity_gb': 22.76, 'driver_version': u'3.0.0', u'location_info': u'LVMVolumeDriver:DevStack-Rocky-Controller-21:stack-volumes-lvmdriver-1:thin:0', u'total_capacity_gb': 22.8, u'thick_provisioning_support': False, u'reserved_percentage': 0, u'QoS_support': False, u'max_over_subscription_ratio': u'20.0', 'vendor_name': u'Open Source', 'storage_protocol': u'iSCSI', u'backend_state': u'up'} {{(pid=21820) update_from_volume_capability /opt/stack/cinder/cinder/scheduler/host_manager.py:358}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Updating capabilities for DevStack-Rocky-Compute-22@lvmdriver-1#lvmdriver-1: {u'pool_name': u'lvmdriver-1', u'filter_function': None, u'goodness_function': None, u'multiattach': True, u'total_volumes': 2, u'provisioned_capacity_gb': 1.0, 'timestamp': datetime.datetime(2019, 7, 3, 14, 5, 6, 539368), u'allocated_capacity_gb': 1, 'volume_backend_name': u'lvmdriver-1', u'thin_provisioning_support': True, u'free_capacity_gb': 21.8, 'driver_version': u'3.0.0', u'location_info': u'LVMVolumeDriver:DevStack-Rocky-Compute-22:stack-volumes-lvmdriver-1:thin:0', u'total_capacity_gb': 22.8, u'thick_provisioning_support': False, u'reserved_percentage': 0, u'QoS_support': False, u'max_over_subscription_ratio': u'20.0', 'vendor_name': u'Open Source', 'storage_protocol': u'iSCSI', u'backend_state': u'up'} {{(pid=21820) update_from_volume_capability /opt/stack/cinder/cinder/scheduler/host_manager.py:358}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Updating capabilities for DevStack-Rocky-Compute-22@nfs#nfs: {u'goodness_function': None, u'thick_provisioning_support': False, u'provisioned_capacity_gb': 0.0, 'timestamp': datetime.datetime(2019, 7, 3, 14, 5, 13, 980234), u'allocated_capacity_gb': 0, u'volume_backend_name': u'nfs', u'thin_provisioning_support': True, u'driver_version': u'1.4.0', u'total_capacity_gb': 4921.4189453125, u'sparse_copy_volume': True, u'reserved_percentage': 0, u'filter_function': None, u'QoS_support': False, u'free_capacity_gb': 2395.5595703125, u'max_over_subscription_ratio': 20.0, u'vendor_name': u'Open Source', u'storage_protocol': u'nfs'} {{(pid=21820) update_from_volume_capability /opt/stack/cinder/cinder/scheduler/host_manager.py:358}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Updating capabilities for DevStack-Rocky-Controller-21@nfs#nfs: {u'goodness_function': None, u'thick_provisioning_support': False, u'provisioned_capacity_gb': 2.0, 'timestamp': datetime.datetime(2019, 7, 3, 14, 4, 58, 239636), u'allocated_capacity_gb': 0, u'volume_backend_name': u'nfs', u'thin_provisioning_support': True, u'driver_version': u'1.4.0', u'total_capacity_gb': 4921.4189453125, u'sparse_copy_volume': True, u'reserved_percentage': 0, u'filter_function': None, u'QoS_support': False, u'free_capacity_gb': 2395.5595703125, u'max_over_subscription_ratio': 20.0, u'vendor_name': u'Open Source', u'storage_protocol': u'nfs'} {{(pid=21820) update_from_volume_capability /opt/stack/cinder/cinder/scheduler/host_manager.py:358}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] http://10.12.30.21/volume/v3/9ed27f1df9814f91b370d1003b066b0a/volumes returned with HTTP 202

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.base_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Starting with 4 host(s) {{(pid=21820) get_filtered_objects /opt/stack/cinder/cinder/scheduler/base_filter.py:95}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.base_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Filter AvailabilityZoneFilter returned 4 host(s) {{(pid=21820) get_filtered_objects /opt/stack/cinder/cinder/scheduler/base_filter.py:125}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking if host DevStack-Rocky-Compute-22@lvmdriver-1#lvmdriver-1 can create a 1 GB volume (07acd9e8-def4-434a-8657-d6c257929b67) {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:62}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking provisioning for request of 1 GB. Backend: host 'DevStack-Rocky-Compute-22@lvmdriver-1#lvmdriver-1':free_capacity_gb: 21.8, total_capacity_gb: 22.8,allocated_capacity_gb: 1, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 1.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:06.539368 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:134}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Space information for volume creation on host DevStack-Rocky-Compute-22@lvmdriver-1#lvmdriver-1 (requested / avail): 1/21.8 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:172}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking if host DevStack-Rocky-Controller-21@lvmdriver-1#lvmdriver-1 can create a 1 GB volume (07acd9e8-def4-434a-8657-d6c257929b67) {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:62}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking provisioning for request of 1 GB. Backend: host 'DevStack-Rocky-Controller-21@lvmdriver-1#lvmdriver-1':free_capacity_gb: 22.76, total_capacity_gb: 22.8,allocated_capacity_gb: 2, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 3.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:01.623563 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:134}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Space information for volume creation on host DevStack-Rocky-Controller-21@lvmdriver-1#lvmdriver-1 (requested / avail): 1/22.76 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:172}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking if host DevStack-Rocky-Compute-22@nfs#nfs can create a 1 GB volume (07acd9e8-def4-434a-8657-d6c257929b67) {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:62}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking provisioning for request of 1 GB. Backend: host 'DevStack-Rocky-Compute-22@nfs#nfs':free_capacity_gb: 2395.55957031, total_capacity_gb: 4921.41894531,allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 0.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:13.980234 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:134}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Space information for volume creation on host DevStack-Rocky-Compute-22@nfs#nfs (requested / avail): 1/2395.55957031 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:172}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking if host DevStack-Rocky-Controller-21@nfs#nfs can create a 1 GB volume (07acd9e8-def4-434a-8657-d6c257929b67) {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:62}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Checking provisioning for request of 1 GB. Backend: host 'DevStack-Rocky-Controller-21@nfs#nfs':free_capacity_gb: 2395.55957031, total_capacity_gb: 4921.41894531,allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 2.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:04:58.239636 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:134}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capacity_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Space information for volume creation on host DevStack-Rocky-Controller-21@nfs#nfs (requested / avail): 1/2395.55957031 {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capacity_filter.py:172}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.base_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Filter CapacityFilter returned 4 host(s) {{(pid=21820) get_filtered_objects /opt/stack/cinder/cinder/scheduler/base_filter.py:125}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capabilities_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Volume type extra spec requirement "volume_backend_name=nfs" does not match reported capability "lvmdriver-1" {{(pid=21820) _satisfies_extra_specs /opt/stack/cinder/cinder/scheduler/filters/capabilities_filter.py:89}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capabilities_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] host 'DevStack-Rocky-Compute-22@lvmdriver-1#lvmdriver-1':free_capacity_gb: 21.8, total_capacity_gb: 22.8,allocated_capacity_gb: 1, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 1.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:06.539368 fails resource_type extra_specs requirements {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capabilities_filter.py:101}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capabilities_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Volume type extra spec requirement "volume_backend_name=nfs" does not match reported capability "lvmdriver-1" {{(pid=21820) _satisfies_extra_specs /opt/stack/cinder/cinder/scheduler/filters/capabilities_filter.py:89}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filters.capabilities_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] host 'DevStack-Rocky-Controller-21@lvmdriver-1#lvmdriver-1':free_capacity_gb: 22.76, total_capacity_gb: 22.8,allocated_capacity_gb: 2, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 3.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:01.623563 fails resource_type extra_specs requirements {{(pid=21820) backend_passes /opt/stack/cinder/cinder/scheduler/filters/capabilities_filter.py:101}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.base_filter [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Filter CapabilitiesFilter returned 2 host(s) {{(pid=21820) get_filtered_objects /opt/stack/cinder/cinder/scheduler/base_filter.py:125}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filter_scheduler [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Filtered [host 'DevStack-Rocky-Compute-22@nfs#nfs':free_capacity_gb: 2395.55957031, total_capacity_gb: 4921.41894531,allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 0.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:13.980234, host 'DevStack-Rocky-Controller-21@nfs#nfs':free_capacity_gb: 2395.55957031, total_capacity_gb: 4921.41894531,allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 2.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:04:58.239636] {{(pid=21820) _get_weighted_candidates /opt/stack/cinder/cinder/scheduler/filter_scheduler.py:342}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.base_weight [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Weigher CapacityWeigher returned, weigher value is {max: 98428.3789062, min: 98426.3789062} {{(pid=21820) get_weighed_objects /opt/stack/cinder/cinder/scheduler/base_weight.py:153}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Weighed [WeighedHost [host: DevStack-Rocky-Compute-22@nfs#nfs, weight: 1.0], WeighedHost [host: DevStack-Rocky-Controller-21@nfs#nfs, weight: 0.0]] {{(pid=21820) get_weighed_backends /opt/stack/cinder/cinder/scheduler/host_manager.py:500}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.filter_scheduler [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Choosing DevStack-Rocky-Compute-22@nfs#nfs {{(pid=21820) _choose_top_backend /opt/stack/cinder/cinder/scheduler/filter_scheduler.py:563}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.host_manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Consumed 1 GB from backend: host 'DevStack-Rocky-Compute-22@nfs#nfs':free_capacity_gb: 2394.55957031, total_capacity_gb: 4921.41894531,allocated_capacity_gb: 1, max_over_subscription_ratio: 20.0,reserved_percentage: 0, provisioned_capacity_gb: 1.0,thin_provisioning_support: True, thick_provisioning_support: False,pools: None,updated at: 2019-07-03 14:05:27.232608 {{(pid=21820) consume_from_volume /opt/stack/cinder/cinder/scheduler/host_manager.py:316}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.scheduler.flows.create_volume.ScheduleCreateVolumeTask;volume:create' (2095b82b-32ed-4829-aee4-6450ca7473be) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=21820) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 cinder-scheduler: DEBUG cinder.scheduler.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Flow 'volume_create_scheduler' (2947b22f-db94-42b0-b747-34abcc8eb146) transitioned into state 'SUCCESS' from state 'RUNNING' {{(pid=21820) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] GET http://10.12.30.21/volume//

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Empty body provided in request {{(pid=21070) get_body /opt/stack/cinder/cinder/api/openstack/wsgi.py:718}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: DEBUG cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] Calling method 'all' {{(pid=21070) _process_stack /opt/stack/cinder/cinder/api/openstack/wsgi.py:872}}

Jul  3 22:05:27 DevStack-Rocky-Controller-21 devstack@c-api.service: INFO cinder.api.openstack.wsgi [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin admin] http://10.12.30.21/volume// returned with HTTP 300

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.flows.manager.create_volume [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Volume reschedule parameters: True retry: {u'num_attempts': 1, u'backends': [u'DevStack-Rocky-Compute-22@nfs#nfs'], u'hosts': [u'DevStack-Rocky-Compute-22@nfs#nfs']} {{(pid=23760) get_flow /opt/stack/cinder/cinder/volume/flows/manager/create_volume.py:1171}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: WARNING castellan.key_manager.migration [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Using MigrationKeyManager to provide support for legacy fixed_key encryption

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Flow 'volume_create_manager' (ab2b2e27-efde-432f-8a61-4f0ac712db01) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (3ea2bb0e-3036-4ff9-b2bd-408ec7a213b9) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_db.sqlalchemy.engines [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION {{(pid=23760) _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:308}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (3ea2bb0e-3036-4ff9-b2bd-408ec7a213b9) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2019-07-03T14:05:27Z,deleted=False,deleted_at=None,display_description='',display_name='nfs-vol-xx',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='DevStack-Rocky-Compute-22@nfs#nfs',id=07acd9e8-def4-434a-8657-d6c257929b67,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='9ed27f1df9814f91b370d1003b066b0a',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2019-07-03T14:05:27Z,service_uuid=None,shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='creating',terminated_at=None,updated_at=2019-07-03T14:05:27Z,user_id='0acd431e550c4309be26a1c52e684605',volume_attachment=<?>,volume_type=VolumeType(68c3bab8-d6cd-4add-823e-56383b4e0f3e),volume_type_id=68c3bab8-d6cd-4add-823e-56383b4e0f3e)' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (cce07d00-6cb5-4368-a5c1-dbde466ea594) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (cce07d00-6cb5-4368-a5c1-dbde466ea594) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (3d77e1a8-89b4-4a33-85dc-c63ad1d973fd) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (3d77e1a8-89b4-4a33-85dc-c63ad1d973fd) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'status': u'creating', 'volume_size': 1, 'volume_name': u'volume-07acd9e8-def4-434a-8657-d6c257929b67', 'type': 'raw', 'volume_id': u'07acd9e8-def4-434a-8657-d6c257929b67'}' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (be315300-7f3a-4a53-b77f-e92ac3d7c060) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (be315300-7f3a-4a53-b77f-e92ac3d7c060) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (2049d9c1-f1df-49f6-9d6f-e9ec2544053a) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.flows.manager.create_volume [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Volume 07acd9e8-def4-434a-8657-d6c257929b67: being created as raw with specification: {'status': u'creating', 'volume_size': 1, 'volume_name': u'volume-07acd9e8-def4-434a-8657-d6c257929b67'}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.coordination [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Lock "/opt/stack/data/cinder/cinder-nfs-07acd9e8-def4-434a-8657-d6c257929b67" acquired by "create_volume" :: waited 0.000s {{(pid=23760) _synchronized /opt/stack/cinder/cinder/coordination.py:150}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.nfs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] ==> create_volume: call {'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=2019-07-03T14:05:27Z,deleted=False,deleted_at=None,display_description='',display_name='nfs-vol-xx',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='DevStack-Rocky-Compute-22@nfs#nfs',id=07acd9e8-def4-434a-8657-d6c257929b67,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='9ed27f1df9814f91b370d1003b066b0a',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2019-07-03T14:05:27Z,service_uuid=None,shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='creating',terminated_at=None,updated_at=2019-07-03T14:05:27Z,user_id='0acd431e550c4309be26a1c52e684605',volume_attachment=<?>,volume_type=VolumeType(68c3bab8-d6cd-4add-823e-56383b4e0f3e),volume_type_id=68c3bab8-d6cd-4add-823e-56383b4e0f3e), 'self': <cinder.volume.drivers.nfs.NfsDriver object at 0x7f5978f39410>} {{(pid=23760) trace_logging_wrapper /opt/stack/cinder/cinder/utils.py:914}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Creating volume 07acd9e8-def4-434a-8657-d6c257929b67 {{(pid=23760) create_volume /opt/stack/cinder/cinder/volume/drivers/remotefs.py:268}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Loading shares from /etc/cinder/nfs_shares. {{(pid=23760) _load_shares_config /opt/stack/cinder/cinder/volume/drivers/remotefs.py:499}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] shares loaded: {'10.12.28.8:/home/nfs1': None} {{(pid=23760) _load_shares_config /opt/stack/cinder/cinder/volume/drivers/remotefs.py:531}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Running cmd (subprocess): mount {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] CMD "mount" returned: 0 in 0.013s {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: INFO os_brick.remotefs.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Already mounted: /nfs_storage/cc6a13e63509492ab709bb63b536feed

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Available shares ['10.12.28.8:/home/nfs1'] {{(pid=23760) _ensure_shares_mounted /opt/stack/cinder/cinder/volume/drivers/remotefs.py:317}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf stat -f -c %S %b %a /nfs_storage/cc6a13e63509492ab709bb63b536feed {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf stat -f -c %S %b %a /nfs_storage/cc6a13e63509492ab709bb63b536feed" returned: 0 in 0.230s {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf du -sb --apparent-size --exclude *snapshot* /nfs_storage/cc6a13e63509492ab709bb63b536feed {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf du -sb --apparent-size --exclude *snapshot* /nfs_storage/cc6a13e63509492ab709bb63b536feed" returned: 0 in 0.224s {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.nfs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Selected 10.12.28.8:/home/nfs1 as target NFS share. {{(pid=23760) _find_share /opt/stack/cinder/cinder/volume/drivers/nfs.py:263}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] casted to 10.12.28.8:/home/nfs1

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf truncate -s 1G /nfs_storage/cc6a13e63509492ab709bb63b536feed/volume-07acd9e8-def4-434a-8657-d6c257929b67 {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf truncate -s 1G /nfs_storage/cc6a13e63509492ab709bb63b536feed/volume-07acd9e8-def4-434a-8657-d6c257929b67" returned: 0 in 0.232s {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: WARNING cinder.volume.drivers.remotefs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] /nfs_storage/cc6a13e63509492ab709bb63b536feed/volume-07acd9e8-def4-434a-8657-d6c257929b67 is being set with open permissions: ugo+rw

Jul  3 22:05:27 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf chmod ugo+rw /nfs_storage/cc6a13e63509492ab709bb63b536feed/volume-07acd9e8-def4-434a-8657-d6c257929b67 {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG oslo_concurrency.processutils [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf chmod ugo+rw /nfs_storage/cc6a13e63509492ab709bb63b536feed/volume-07acd9e8-def4-434a-8657-d6c257929b67" returned: 0 in 0.241s {{(pid=23760) execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.drivers.nfs [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] <== create_volume: return (951ms) {'provider_location': u'10.12.28.8:/home/nfs1'} {{(pid=23760) trace_logging_wrapper /opt/stack/cinder/cinder/utils.py:939}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.coordination [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Lock "/opt/stack/data/cinder/cinder-nfs-07acd9e8-def4-434a-8657-d6c257929b67" released by "create_volume" :: held 0.954s {{(pid=23760) _synchronized /opt/stack/cinder/cinder/coordination.py:162}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (2049d9c1-f1df-49f6-9d6f-e9ec2544053a) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'status': u'creating', 'volume_size': 1, 'volume_name': u'volume-07acd9e8-def4-434a-8657-d6c257929b67'}' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end' (730545d2-d060-4676-b12d-872d04ee7aac) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:194}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.flows.manager.create_volume [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Volume volume-07acd9e8-def4-434a-8657-d6c257929b67 (07acd9e8-def4-434a-8657-d6c257929b67): created successfully

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end' (730545d2-d060-4676-b12d-872d04ee7aac) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=23760) _task_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:183}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: DEBUG cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Flow 'volume_create_manager' (ab2b2e27-efde-432f-8a61-4f0ac712db01) transitioned into state 'SUCCESS' from state 'RUNNING' {{(pid=23760) _flow_receiver /usr/lib/python2.7/site-packages/taskflow/listeners/logging.py:145}}

Jul  3 22:05:28 DevStack-Rocky-Compute-22 cinder-volume: INFO cinder.volume.manager [None req-9c978840-8277-4a5f-b94f-218a76412d1f admin None] Created volume successfully.