Retype encrypted volume failed with libvirt qemu native luks

Bug #1838381 reported by Mai Ngoc Duong on 2019-07-30
22
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Cinder
High
Sofia Enriquez

Bug Description

reproduce:

1. Install Barbican, Cinder volume with ceph backend
2. Create cinder volume type LUKS:
cinder type-create LUKS
cinder encryption-type-create --cipher aes-xts-plain64 --key_size 256 --control_location front-end LUKS nova.volume.encryptors.luks.LuksEncryptor
3. Create 1 unencrypted volume
cinder create --display-name 'unencrypted volume' 1
4. Retype unencrypted volume to LUKS
openstack volume set c3c24afe-579f-468c-8458-41c4b52d46dc --type LUKS --retype-policy on-demand

Version (install binary package on ubuntu)
cinder-* 2:14.0.0-0ubuntu1~cloud0
nova-* 2:19.0.1-0ubuntu1~cloud0
barbican-* 1:8.0.0-0ubuntu1~cloud0
qemu-* 1:3.1+dfsg-2ubuntu3.1~cloud0
libvirt-* 5.0.0-1ubuntu2.1~cloud0

Error log in cinder-volume:

2019-07-30 15:37:11.655 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Creating Client object Client /usr/lib/python3/dist-packages/barbicanclient/client.py:156
2019-07-30 15:37:11.865 27894 DEBUG barbicanclient.v1.orders [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Request body: {'type': 'key', 'meta': {'algorithm': 'aes', 'bit_length': 256}} submit /usr/lib/python3/dist-packages/barbicanclient/v1/orders.py:235
2019-07-30 15:37:12.338 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 202 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:12.340 27894 DEBUG barbicanclient.v1.orders [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Getting order - Order href: http://localhost:9311/v1/orders/0ae8cee9-0f8c-4679-9d3c-7eb6ecfa63a7 get /usr/lib/python3/dist-packages/barbicanclient/v1/orders.py:397
2019-07-30 15:37:12.382 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:12.747 27894 DEBUG cinder.volume.flows.manager.create_volume [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Volume reschedule parameters: False retry: None get_flow /usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py:1100
2019-07-30 15:37:12.760 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Flow 'volume_create_manager' (5b74b90b-c8b4-41e9-b2e7-e21870d45810) transitioned into state 'RUNNING' from state 'PENDING' _flow_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:145
2019-07-30 15:37:12.762 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (5a80db8a-620e-4aa3-a81f-7c07f529db6e) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:12.782 27894 DEBUG oslo_db.sqlalchemy.engines [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] 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 _check_effective_sql_mode /usr/lib/python3/dist-packages/oslo_db/sqlalchemy/engines.py:307
2019-07-30 15:37:12.806 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (5a80db8a-620e-4aa3-a81f-7c07f529db6e) 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-29T03:59:06Z,deleted=False,deleted_at=None,display_description=None,display_name='unencrypted volume',ec2_id=None,encryption_key_id=c36dc0af-23d0-4669-a58a-cf5988f67f1f,glance_metadata=<?>,group=<?>,group_id=None,host='controller@ceph#RBD',id=06a67b1c-8f62-4eee-b7db-b705504b3ffa,launched_at=2019-07-29T03:59:07Z,metadata={},migration_status='target:c3c24afe-579f-468c-8458-41c4b52d46dc',multiattach=False,previous_status='available',project_id='7e985781250646e781010e3a31364590',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-29T03:59:07Z,service_uuid='3a9dc1f1-e163-4d19-a100-bbcb01deba7e',shared_targets=False,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='creating',terminated_at=None,updated_at=2019-07-30T07:33:56Z,user_id='ceeefa7882b34847ae15763607ba0d69',volume_attachment=<?>,volume_type=VolumeType(bbcbe486-d4e8-441d-b72c-55f59553e8c4),volume_type_id=bbcbe486-d4e8-441d-b72c-55f59553e8c4)' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:12.808 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (a7d1156b-e135-4ea0-a121-f31b8590e18c) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:12.810 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (a7d1156b-e135-4ea0-a121-f31b8590e18c) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:12.811 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (0105f79e-4080-4067-bb8c-402150752878) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:12.813 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (0105f79e-4080-4067-bb8c-402150752878) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'status': 'creating', 'type': 'raw', 'volume_id': '06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'volume_name': 'volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'volume_size': 1}' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:12.814 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (7887450a-8317-43ff-b747-7916938c4743) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:12.837 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (7887450a-8317-43ff-b747-7916938c4743) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:12.841 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (98c9d434-3220-4616-bffa-fab5422b3df8) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:12.842 27894 INFO cinder.volume.flows.manager.create_volume [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Volume 06a67b1c-8f62-4eee-b7db-b705504b3ffa: being created as raw with specification: {'status': 'creating', 'volume_name': 'volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'volume_size': 1}
2019-07-30 15:37:12.878 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Creating Client object Client /usr/lib/python3/dist-packages/barbicanclient/client.py:156
2019-07-30 15:37:13.062 27894 DEBUG barbicanclient.v1.secrets [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Getting secret - Secret href: http://controller:9311/v1/secrets/c36dc0af-23d0-4669-a58a-cf5988f67f1f get /usr/lib/python3/dist-packages/barbicanclient/v1/secrets.py:457
2019-07-30 15:37:13.426 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.475 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.514 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.547 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.584 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.614 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.647 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.679 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.712 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.774 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.814 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.847 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.882 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.915 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.949 27894 DEBUG barbicanclient.client [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Response status 200 _check_status_code /usr/lib/python3/dist-packages/barbicanclient/client.py:87
2019-07-30 15:37:13.953 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Running cmd (subprocess): qemu-img create -f luks -o cipher-alg=aes-256,cipher-mode=xts,ivgen-alg=plain64 --object secret,id=luks_sec,format=raw,file=/var/lib/cinder/conversion/tmp0kdf24qi -o key-secret=*** /var/lib/cinder/conversion/tmp0jzevvpx 1024M execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:372
2019-07-30 15:37:18.324 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] CMD "qemu-img create -f luks -o cipher-alg=aes-256,cipher-mode=xts,ivgen-alg=plain64 --object secret,id=luks_sec,format=raw,file=/var/lib/cinder/conversion/tmp0kdf24qi -o key-secret=*** /var/lib/cinder/conversion/tmp0jzevvpx 1024M" returned: 0 in 4.371s execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:409
2019-07-30 15:37:18.327 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Running cmd (subprocess): rbd import --pool volumes --order 22 /var/lib/cinder/conversion/tmp0jzevvpx volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa --id volumes --cluster ceph --conf /etc/ceph/ceph.conf execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:372
2019-07-30 15:37:20.279 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] CMD "rbd import --pool volumes --order 22 /var/lib/cinder/conversion/tmp0jzevvpx volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa --id volumes --cluster ceph --conf /etc/ceph/ceph.conf" returned: 0 in 1.952s execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:409
2019-07-30 15:37:20.376 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (98c9d434-3220-4616-bffa-fab5422b3df8) transitioned into state 'SUCCESS' from state 'RUNNING' with result '{'status': 'creating', 'volume_name': 'volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'volume_size': 1}' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:20.378 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end' (384f60ed-c70b-4b99-8fe8-1daae4febfc4) transitioned into state 'RUNNING' from state 'PENDING' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:194
2019-07-30 15:37:20.414 27894 INFO cinder.volume.flows.manager.create_volume [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Volume volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa (06a67b1c-8f62-4eee-b7db-b705504b3ffa): created successfully
2019-07-30 15:37:20.415 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end' (384f60ed-c70b-4b99-8fe8-1daae4febfc4) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' _task_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:183
2019-07-30 15:37:20.417 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Flow 'volume_create_manager' (5b74b90b-c8b4-41e9-b2e7-e21870d45810) transitioned into state 'SUCCESS' from state 'RUNNING' _flow_receiver /usr/lib/python3/dist-packages/taskflow/listeners/logging.py:145
2019-07-30 15:37:20.428 27894 INFO cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Created volume successfully.
2019-07-30 15:37:23.575 27894 DEBUG oslo_service.periodic_task [req-0bedabc6-c0dd-4f41-88fd-4f0d988bc657 - - - - -] Running periodic task VolumeManager.publish_service_capabilities run_periodic_tasks /usr/lib/python3/dist-packages/oslo_service/periodic_task.py:217
2019-07-30 15:37:23.578 27894 DEBUG cinder.volume.drivers.rbd [req-0bedabc6-c0dd-4f41-88fd-4f0d988bc657 - - - - -] connecting to volumes@ceph (conf=/etc/ceph/ceph.conf, timeout=-1). _do_conn /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:402
2019-07-30 15:37:23.617 27894 DEBUG cinder.volume.drivers.rbd [req-0bedabc6-c0dd-4f41-88fd-4f0d988bc657 - - - - -] connecting to volumes@ceph (conf=/etc/ceph/ceph.conf, timeout=-1). _do_conn /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:402
2019-07-30 15:37:23.651 27894 DEBUG cinder.volume.drivers.rbd [req-0bedabc6-c0dd-4f41-88fd-4f0d988bc657 - - - - -] connecting to volumes@ceph (conf=/etc/ceph/ceph.conf, timeout=-1). _do_conn /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:402
2019-07-30 15:37:23.880 27894 DEBUG cinder.manager [req-0bedabc6-c0dd-4f41-88fd-4f0d988bc657 - - - - -] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python3/dist-packages/cinder/manager.py:194
2019-07-30 15:37:26.899 27894 DEBUG cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] _copy_volume_data volume-c3c24afe-579f-468c-8458-41c4b52d46dc -> volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa. _copy_volume_data /usr/lib/python3/dist-packages/cinder/volume/manager.py:2091
2019-07-30 15:37:26.909 27894 DEBUG os_brick.utils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] ==> get_connector_properties: call "{'root_helper': 'sudo cinder-rootwrap /etc/cinder/rootwrap.conf', 'my_ip': 'controller', 'multipath': False, 'enforce_multipath': False, 'host': None, 'execute': None}" trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:146
2019-07-30 15:37:26.916 30495 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): cat /etc/iscsi/initiatorname.iscsi execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:372
2019-07-30 15:37:26.927 30495 DEBUG oslo_concurrency.processutils [-] CMD "cat /etc/iscsi/initiatorname.iscsi" returned: 0 in 0.012s execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:409
2019-07-30 15:37:26.928 30495 DEBUG oslo.privsep.daemon [-] privsep: reply[139671569934640]: (4, ('## DO NOT EDIT OR REMOVE THIS FILE!\n## If you remove this file, the iSCSI daemon will not start.\n## If you change the InitiatorName, existing access control lists\n## may reject this initiator. The InitiatorName must be unique\n## for each iSCSI initiator. Do NOT duplicate iSCSI InitiatorNames.\nInitiatorName=iqn.1993-08.org.debian:01:5cfb20ba85f0\n', '')) _call_back /usr/lib/python3/dist-packages/oslo_privsep/daemon.py:472
2019-07-30 15:37:26.930 27894 DEBUG os_brick.initiator.linuxfc [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] No Fibre Channel support detected on system. get_fc_hbas /usr/lib/python3/dist-packages/os_brick/initiator/linuxfc.py:134
2019-07-30 15:37:26.930 27894 DEBUG os_brick.initiator.linuxfc [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] No Fibre Channel support detected on system. get_fc_hbas /usr/lib/python3/dist-packages/os_brick/initiator/linuxfc.py:134
2019-07-30 15:37:26.934 30495 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): cat /sys/class/dmi/id/product_uuid execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:372
2019-07-30 15:37:26.945 30495 DEBUG oslo_concurrency.processutils [-] CMD "cat /sys/class/dmi/id/product_uuid" returned: 0 in 0.012s execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:409
2019-07-30 15:37:26.946 30495 DEBUG oslo.privsep.daemon [-] privsep: reply[139671569934640]: (4, ('CA77BF8E-4D1B-498F-A80D-B5D4F1A1FD64\n', '')) _call_back /usr/lib/python3/dist-packages/oslo_privsep/daemon.py:472
2019-07-30 15:37:26.947 27894 DEBUG os_brick.utils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] <== get_connector_properties: return (36ms) {'platform': 'x86_64', 'os_type': 'linux', 'ip': 'controller', 'host': 'controller', 'multipath': False, 'initiator': 'iqn.1993-08.org.debian:01:5cfb20ba85f0', 'do_local_attach': False, 'system uuid': 'CA77BF8E-4D1B-498F-A80D-B5D4F1A1FD64'} trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:170
2019-07-30 15:37:26.956 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Running cmd (subprocess): ceph mon dump --format=json --id volumes --cluster ceph --conf /etc/ceph/ceph.conf execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:372
2019-07-30 15:37:27.274 27894 DEBUG oslo_concurrency.processutils [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] CMD "ceph mon dump --format=json --id volumes --cluster ceph --conf /etc/ceph/ceph.conf" returned: 0 in 0.318s execute /usr/lib/python3/dist-packages/oslo_concurrency/processutils.py:409
2019-07-30 15:37:27.278 27894 DEBUG cinder.volume.drivers.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] connection data: {'driver_volume_type': 'rbd', 'data': {'name': 'volumes/volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'hosts': ['192.168.28.51', '192.168.28.52', '192.168.28.53'], 'ports': ['6789', '6789', '6789'], 'cluster_name': 'ceph', 'auth_enabled': True, 'auth_username': 'volumes', 'secret_type': 'ceph', 'secret_uuid': '94019c72-1928-4303-8364-c339592c8cdb', 'volume_id': '06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'discard': True, 'keyring': None}} initialize_connection /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:1404
2019-07-30 15:37:27.300 27894 INFO cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Initialize volume connection completed successfully.
2019-07-30 15:37:27.305 27894 DEBUG os_brick.initiator.connector [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Factory for rbd on None factory /usr/lib/python3/dist-packages/os_brick/initiator/connector.py:277
2019-07-30 15:37:27.306 27894 DEBUG os_brick.initiator.connectors.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] ==> connect_volume: call "{'self': <os_brick.initiator.connectors.rbd.RBDConnector object at 0x7f07d22693c8>, 'connection_properties': {'name': 'volumes/volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'hosts': ['192.168.28.51', '192.168.28.52', '192.168.28.53'], 'ports': ['6789', '6789', '6789'], 'cluster_name': 'ceph', 'auth_enabled': True, 'auth_username': 'volumes', 'secret_type': 'ceph', 'secret_uuid': '***', 'volume_id': '06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'discard': True, 'keyring': None, 'qos_specs': None, 'access_mode': 'rw', 'encrypted': True}}" trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:146
2019-07-30 15:37:27.308 27894 DEBUG os_brick.initiator.linuxrbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] opening connection to ceph cluster (timeout=-1). connect /usr/lib/python3/dist-packages/os_brick/initiator/linuxrbd.py:70
2019-07-30 15:37:27.430 27894 DEBUG os_brick.initiator.connectors.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] <== connect_volume: return (122ms) {'path': <os_brick.initiator.linuxrbd.RBDVolumeIOWrapper object at 0x7f07d22f8438>} trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:170
2019-07-30 15:37:27.481 27894 WARNING os_brick.encryptors [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Use of the in tree encryptor class nova.volume.encryptors.luks.LuksEncryptor by directly referencing the implementation class will be blocked in the Queens release of os-brick.
2019-07-30 15:37:27.482 27894 ERROR os_brick.encryptors [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Error instantiating os_brick.encryptors.luks.LuksEncryptor: expected str, bytes or os.PathLike object, not RBDVolumeIOWrapper
2019-07-30 15:37:27.483 27894 ERROR cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Failed to attach volume encryptor 06a67b1c-8f62-4eee-b7db-b705504b3ffa.
2019-07-30 15:37:27.484 27894 DEBUG os_brick.initiator.connectors.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] ==> disconnect_volume: call "{'self': <os_brick.initiator.connectors.rbd.RBDConnector object at 0x7f07d22693c8>, 'connection_properties': {'name': 'volumes/volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'hosts': ['192.168.28.51', '192.168.28.52', '192.168.28.53'], 'ports': ['6789', '6789', '6789'], 'cluster_name': 'ceph', 'auth_enabled': True, 'auth_username': 'volumes', 'secret_type': 'ceph', 'secret_uuid': '***', 'volume_id': '06a67b1c-8f62-4eee-b7db-b705504b3ffa', 'discard': True, 'keyring': None, 'qos_specs': None, 'access_mode': 'rw', 'encrypted': True, 'device_path': <os_brick.initiator.linuxrbd.RBDVolumeIOWrapper object at 0x7f07d22f8438>}, 'device_info': {'path': <os_brick.initiator.linuxrbd.RBDVolumeIOWrapper object at 0x7f07d22f8438>}, 'force': True, 'ignore_errors': False}" trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:146
2019-07-30 15:37:27.563 27894 DEBUG os_brick.initiator.connectors.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] <== disconnect_volume: return (79ms) None trace_logging_wrapper /usr/lib/python3/dist-packages/os_brick/utils.py:170
2019-07-30 15:37:27.601 27894 INFO cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Terminate volume connection completed successfully.
2019-07-30 15:37:27.635 27894 INFO cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Remove volume export completed successfully.
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Failed to copy volume c3c24afe-579f-468c-8458-41c4b52d46dc to 06a67b1c-8f62-4eee-b7db-b705504b3ffa: TypeError: expected str, bytes or os.PathLike object, not RBDVolumeIOWrapper
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager Traceback (most recent call last):
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2229, in _migrate_volume_generic
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager self._copy_volume_data(ctxt, volume, new_volume, remote='dest')
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2109, in _copy_volume_data
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager attach_encryptor=attach_encryptor)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2056, in _attach_volume
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager force=True)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager self.force_reraise()
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager six.reraise(self.type_, self.value, self.tb)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager raise value
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2050, in _attach_volume
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager encryption)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/utils.py", line 535, in brick_attach_volume_encryptor
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager **encryption)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/cinder/utils.py", line 527, in brick_get_encryptor
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager *args, **kwargs)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/os_brick/encryptors/__init__.py", line 91, in get_volume_encryptor
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager **kwargs)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/oslo_utils/importutils.py", line 44, in import_object
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager return import_class(import_str)(*args, **kwargs)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/os_brick/encryptors/luks.py", line 61, in __init__
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager *args, **kwargs)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3/dist-packages/os_brick/encryptors/cryptsetup.py", line 60, in __init__
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager self.dev_name = 'crypt-%s' % os.path.basename(self.symlink_path)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager File "/usr/lib/python3.6/posixpath.py", line 146, in basename
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager p = os.fspath(p)
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager TypeError: expected str, bytes or os.PathLike object, not RBDVolumeIOWrapper
2019-07-30 15:37:27.636 27894 ERROR cinder.volume.manager
2019-07-30 15:37:27.648 27894 DEBUG cinder.coordination [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Lock "/var/lib/cinder/cinder-06a67b1c-8f62-4eee-b7db-b705504b3ffa-delete_volume" acquired by "delete_volume" :: waited 0.001s _synchronized /usr/lib/python3/dist-packages/cinder/coordination.py:150
2019-07-30 15:37:27.742 27894 DEBUG cinder.volume.drivers.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] connecting to volumes@ceph (conf=/etc/ceph/ceph.conf, timeout=-1). _do_conn /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:402
2019-07-30 15:37:27.876 27894 DEBUG cinder.volume.drivers.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] volume has no backup snaps _delete_backup_snaps /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:967
2019-07-30 15:37:27.877 27894 DEBUG cinder.volume.drivers.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Volume volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa is not a clone. _get_clone_info /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:990
2019-07-30 15:37:27.969 27894 DEBUG cinder.volume.drivers.rbd [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] deleting rbd volume volume-06a67b1c-8f62-4eee-b7db-b705504b3ffa delete_volume /usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py:1102
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Exception during message handling: TypeError: expected str, bytes or os.PathLike object, not RBDVolumeIOWrapper
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/server.py", line 166, in _process_incoming
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 265, in dispatch
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2895, in retype
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server new_reservations, status_update)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server raise value
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2891, in retype
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server new_type_id=new_type_id)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2496, in migrate_volume
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server volume.save()
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server raise value
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2489, in migrate_volume
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self._migrate_volume_generic(ctxt, volume, host, new_type_id)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2251, in _migrate_volume_generic
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server new_volume)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server raise value
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2229, in _migrate_volume_generic
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self._copy_volume_data(ctxt, volume, new_volume, remote='dest')
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2109, in _copy_volume_data
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server attach_encryptor=attach_encryptor)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2056, in _attach_volume
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server force=True)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server raise value
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 2050, in _attach_volume
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server encryption)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/utils.py", line 535, in brick_attach_volume_encryptor
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server **encryption)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/cinder/utils.py", line 527, in brick_get_encryptor
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server *args, **kwargs)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/encryptors/__init__.py", line 91, in get_volume_encryptor
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server **kwargs)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/importutils.py", line 44, in import_object
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server return import_class(import_str)(*args, **kwargs)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/encryptors/luks.py", line 61, in __init__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server *args, **kwargs)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/encryptors/cryptsetup.py", line 60, in __init__
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server self.dev_name = 'crypt-%s' % os.path.basename(self.symlink_path)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.6/posixpath.py", line 146, in basename
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server p = os.fspath(p)
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server TypeError: expected str, bytes or os.PathLike object, not RBDVolumeIOWrapper
2019-07-30 15:37:28.112 27894 ERROR oslo_messaging.rpc.server
2019-07-30 15:37:28.912 27894 WARNING py.warnings [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] /usr/lib/python3/dist-packages/sqlalchemy/orm/evaluator.py:71: SAWarning: Evaluating non-mapped column expression 'updated_at' onto ORM instances; this is a deprecated use case. Please make use of the actual mapped columns in ORM-evaluated UPDATE / DELETE expressions.
  "UPDATE / DELETE expressions." % clause)

2019-07-30 15:37:28.953 27894 INFO cinder.volume.manager [req-3c245597-5e1f-429d-838e-e4cb00b7a392 ceeefa7882b34847ae15763607ba0d69 7e985781250646e781010e3a31364590 - default default] Deleted volume successfully.

Paul Peereboom (peereb) wrote :

Can confirm issue, we have the same on our cloud.

Changed in cinder:
status: New → Confirmed
Changed in cinder:
assignee: nobody → Sofia Enriquez (lsofia-enriquez)
importance: Undecided → High
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers