Instance resize with swap on lvm logical volume fails

Bug #1755266 reported by Dr. Clemens Hardewig
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Confirmed
Low
Dr. Clemens Hardewig

Bug Description

Environment:

Nova on Pike and Queens with kvm/libvirt compute driver

Versions tested:
ii nova-common 2:17.0.0-0ubuntu1~cloud0 all OpenStack Compute - common files
ii nova-compute 2:17.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node base
ii nova-compute-kvm 2:17.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node (KVM)
ii nova-compute-libvirt 2:17.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node libvirt support
ii python-nova 2:17.0.0-0ubuntu1~cloud0 all OpenStack Compute Python libraries
ii python-novaclient 2:9.1.1-0ubuntu1~cloud0 all client library for OpenStack Compute API - Python 2.7
ii python3-novaclient 2:9.1.1-0ubuntu1~cloud0 all client library for OpenStack Compute API - 3.x

Storage on cinder and lvm backend

ii cinder-common 2:12.0.0-0ubuntu1~cloud0 all Cinder storage service - common files
ii cinder-volume 2:12.0.0-0ubuntu1~cloud0 all Cinder storage service - Volume server
ii python-cinder 2:12.0.0-0ubuntu1~cloud0 all Cinder Python libraries
ii python-cinderclient 1:3.5.0-0ubuntu1~cloud0 all Python bindings to the OpenStack Volume API - Python 2.x
ii python3-cinderclient 1:3.5.0-0ubuntu1~cloud0 all Python bindings to the OpenStack Volume API - Python 3.x

Network with Neutron
ii neutron-common 2:12.0.0-0ubuntu1~cloud0 all Neutron is a virtual network service for Openstack - common
rc neutron-linuxbridge-agent 2:11.0.2-0ubuntu1.1~cloud0 all Neutron is a virtual network service for Openstack - linuxbridge agent
ii neutron-openvswitch-agent 2:12.0.0-0ubuntu1~cloud0 all Neutron is a virtual network service for Openstack - Open vSwitch plugin agent
ii python-neutron 2:12.0.0-0ubuntu1~cloud0 all Neutron is a virtual network service for Openstack - Python library
ii python-neutron-fwaas 1:12.0.0-0ubuntu1~cloud0 all Firewall-as-a-Service driver for OpenStack Neutron
ii python-neutron-lib 1.13.0-0ubuntu1~cloud0 all Neutron shared routines and utilities - Python 2.7
ii python-neutronclient 1:6.7.0-0ubuntu1~cloud0 all client API library for Neutron - Python 2.7
ii python3-neutronclient 1:6.7.0-0ubuntu1~cloud0 all client API library for Neutron - Python 3.x

Steps to reproduce:
1.) Start a nova instance with a flavor which has a swap volume
Root Volume is created as /dev/cinder-volume/volume-UUID
The swap volume is created as /dev/cinder-volume/<UUID>_disk.swap

2.) Resize the instance to a different flavor with swap storage via horizon or CLI

Expected Result:

1.) The swap volume on Node 1 is dropped
2.) A new swap volume is created on Node 2 and the instance is migrated/restarted to node 2

Actual result:
1.) The swap volume is tried to be COPIED via scp from Node 1 to Node 2
2.) The source address is assumed to be /var/lib/nova/instances/<uuid>_disk.swap
3.) This fails with 'No such file or directory'(SIC) as swap volume is /dev/cinder-volume/<UUID>_disk.swap
4.) Resizing leaves instance in error mode

Logfile:
 (...)
2018-03-12 17:08:51.771 15427 DEBUG os_brick.initiator.connectors.iscsi [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] <== disconnect_volume: return (678ms) None trace_logging_wrapper /usr/lib/python2.7/dist-packages/os_brick/utils.py:170
2018-03-12 17:08:51.772 15427 DEBUG nova.virt.libvirt.volume.iscsi [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Disconnected iSCSI Volume disconnect_volume /usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/iscsi.py:78
2018-03-12 17:08:51.774 15427 DEBUG nova.virt.libvirt.driver [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] skipping disk /dev/sdo (vda) as it is a volume _get_instance_disk_info_from_config /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:7722
2018-03-12 17:08:51.774 15594 DEBUG oslo.privsep.daemon [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] privsep: request[139660391538352]: (3, 'nova.privsep.fs.blockdev_size', ('/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap',), {}) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:443
2018-03-12 17:08:51.775 15594 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): blockdev --getsize64 /dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:51.781 15594 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "blockdev --getsize64 /dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap" returned: 0 in 0.007s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:51.782 15594 DEBUG oslo.privsep.daemon [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] privsep: reply[139660391538352]: (4, ('2097152000\n', '')) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:456
2018-03-12 17:08:51.783 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): mv /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:51.798 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "mv /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize" returned: 0 in 0.015s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:51.799 15427 DEBUG nova.virt.libvirt.volume.remotefs [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Copying file /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap to 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap copy_file /usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py:107
2018-03-12 17:08:51.799 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:51.965 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap" returned: 1 in 0.166s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:51.966 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] u'scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap' failed. Not Retrying. execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:457
2018-03-12 17:08:51.967 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): rm -rf /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:51.983 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "rm -rf /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82" returned: 0 in 0.016s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:51.984 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): mv /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:51.999 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "mv /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82" returned: 0 in 0.015s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:52.000 15427 DEBUG nova.virt.libvirt.volume.remotefs [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Removing directory /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 on remote host 10.0.88.31 remove_dir /usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py:101
2018-03-12 17:08:52.000 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): ssh -o BatchMode=yes 10.0.88.31 rm -rf /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82 execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:52.132 15427 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "ssh -o BatchMode=yes 10.0.88.31 rm -rf /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82" returned: 0 in 0.132s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Setting instance vm_state to ERROR: ProcessExecutionError: Unexpected error while running command.
Command: scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap
Exit code: 1
Stdout: u''
Stderr: u'/var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap: No such file or directory\n'
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Traceback (most recent call last):
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 7395, in _error_out_instance_on_exception
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] yield
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 4247, in resize_instance
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] timeout, retry_interval)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 8039, in migrate_disk_and_power_off
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] shared_storage)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] self.force_reraise()
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] six.reraise(self.type_, self.value, self.tb)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 8024, in migrate_disk_and_power_off
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] compression=compression)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/utils.py", line 226, in copy_image
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] compression=compression)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py", line 110, in copy_file
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] compression=compression)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py", line 196, in copy_file
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] on_execute=on_execute, on_completion=on_completion)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 231, in execute
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] return processutils.execute(*cmd, **kwargs)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] File "/usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 424, in execute
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] cmd=sanitized_cmd)
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] ProcessExecutionError: Unexpected error while running command.
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Command: scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Exit code: 1
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Stdout: u''
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Stderr: u'/var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap: No such file or directory\n'
2018-03-12 17:08:52.191 15427 ERROR nova.compute.manager [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82]
2018-03-12 17:08:52.696 15427 DEBUG oslo_concurrency.lockutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Lock "compute_resources" acquired by "nova.compute.resource_tracker.update_usage" :: waited 0.000s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:276
2018-03-12 17:08:52.758 15594 DEBUG oslo.privsep.daemon [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] privsep: request[139660391538352]: (3, 'nova.privsep.fs.vginfo', ('cinder-volumes',), {}) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:443
2018-03-12 17:08:52.758 15594 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Running cmd (subprocess): vgs --noheadings --nosuffix --separator | --units b -o vg_size,vg_free cinder-volumes execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:372
2018-03-12 17:08:52.783 15594 DEBUG oslo_concurrency.processutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] CMD "vgs --noheadings --nosuffix --separator | --units b -o vg_size,vg_free cinder-volumes" returned: 0 in 0.024s execute /usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py:409
2018-03-12 17:08:52.783 15594 DEBUG oslo.privsep.daemon [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] privsep: reply[139660391538352]: (4, (' 3000454086656|2075542945792\n', '')) loop /usr/lib/python2.7/dist-packages/oslo_privsep/daemon.py:456
2018-03-12 17:08:52.799 15427 DEBUG nova.compute.provider_tree [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Updating resource provider 1c1ad99d-3976-4aa8-bf32-3394f6c2040f generation from 53 to 54 _update_generation /usr/lib/python2.7/dist-packages/nova/compute/provider_tree.py:153
2018-03-12 17:08:52.800 15427 DEBUG oslo_concurrency.lockutils [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Lock "compute_resources" released by "nova.compute.resource_tracker.update_usage" :: held 0.104s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:288
2018-03-12 17:08:52.800 15427 INFO nova.compute.manager [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] Successfully reverted task state from resize_migrating on failure for instance.
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Exception during message handling: ProcessExecutionError: Unexpected error while running command.
Command: scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap
Exit code: 1
Stdout: u''
Stderr: u'/var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap: No such file or directory\n'
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/exception_wrapper.py", line 76, in wrapped
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server function_name, call_dict, binary)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server self.force_reraise()
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/exception_wrapper.py", line 67, in wrapped
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 186, in decorated_function
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server "Error: %s", e, instance=instance)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server self.force_reraise()
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 156, in decorated_function
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/utils.py", line 976, in decorated_function
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 214, in decorated_function
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server kwargs['instance'], e, sys.exc_info())
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server self.force_reraise()
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 202, in decorated_function
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 4247, in resize_instance
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server timeout, retry_interval)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 8039, in migrate_disk_and_power_off
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server shared_storage)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server self.force_reraise()
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 8024, in migrate_disk_and_power_off
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server compression=compression)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/utils.py", line 226, in copy_image
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server compression=compression)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py", line 110, in copy_file
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server compression=compression)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume/remotefs.py", line 196, in copy_file
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server on_execute=on_execute, on_completion=on_completion)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 231, in execute
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server return processutils.execute(*cmd, **kwargs)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 424, in execute
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server cmd=sanitized_cmd)
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server ProcessExecutionError: Unexpected error while running command.
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server Command: scp -r /var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap 10.0.88.31:/dev/cinder-volumes/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server Exit code: 1
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server Stdout: u''
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server Stderr: u'/var/lib/nova/instances/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_resize/1ae5b6ee-aa77-4661-8542-58bd9da5ef82_disk.swap: No such file or directory\n'
2018-03-12 17:08:52.829 15427 ERROR oslo_messaging.rpc.server
2018-03-12 17:09:06.091 15427 DEBUG nova.virt.driver [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] Emitting event <LifecycleEvent: 1520870931.09, 1ae5b6ee-aa77-4661-8542-58bd9da5ef82 => Stopped> emit_event /usr/lib/python2.7/dist-packages/nova/virt/driver.py:1514
2018-03-12 17:09:06.092 15427 INFO nova.compute.manager [req-c85ef642-2708-4395-bcf4-3a3f8820a39e 9fce36209f42437bb9d4e5d4423586ae 87cbad1ec81143b5bbc557a40d81c81a - default default] [instance: 1ae5b6ee-aa77-4661-8542-58bd9da5ef82] VM Stopped (Lifecycle Event)

Instance need then to be destroyed and removed

Br br

Matt Riedemann (mriedem)
tags: added: resize volumes
Revision history for this message
Matt Riedemann (mriedem) wrote :

I'm a bit confused about the 'swap volume' terminology here. As far as I know, swap disks are never stored as cinder volumes, they are ephemeral storage on the local compute host, as noted here:

https://docs.openstack.org/nova/latest/user/block-device-mapping.html#block-device-mapping-v2

"guest_format - Tells Nova how/if to format the device prior to attaching, should be only used with blank local images. Denotes a swap disk if the value is swap."

Are we talking about the same thing? And just the issue is that during the resize, the swap disk is not re-created on the destination host?

Revision history for this message
Dr. Clemens Hardewig (bringha1) wrote :
Download full text (4.9 KiB)

Hi Matt,

thanks for your reply!

My set up has a cinder volume service with lvm2 on each compute host. Confusion might come from the fact that the vg 'cinder-volume' is the only volume group visible to libvirt guests. According to the cinder recommendation, I have filtered out all other vg's so that they are not visible on openstack level. This does NOT mean that cinder creates the swap volume ...

The standard flavors assume swap devices when creating an instance and if I look into the libvirt xml files /etc/libvirt/qemu/instance-00000xxx.xml), this swap device is created then in the volume group 'cinder-volume'. The lines in the xml files are:

(...)
<metadata>
    <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
      <nova:package version="16.0.3"/>
      <nova:name>datenbankserver</nova:name>
      <nova:creationTime>2018-03-02 21:24:07</nova:creationTime>
      <nova:flavor name="m1.medium">
        <nova:memory>4000</nova:memory>
        <nova:disk>40</nova:disk>
        <nova:swap>4000</nova:swap>
        <nova:ephemeral>0</nova:ephemeral>
        <nova:vcpus>2</nova:vcpus>
      </nova:flavor>
      <nova:owner>
        <nova:user uuid="8287f31XXXXXXXXXXXXXXXXX">user_name</nova:user>
        <nova:project uuid="18e26500a53944XXXXXXXXXXXXX">project_name</nova:project>
      </nova:owner>
    </nova:instance>
  </metadata>

(...)

<devices>
    <emulator>/usr/bin/kvm-spice</emulator>
    <disk type='block' device='disk'>
      <driver name='qemu' type='raw' cache='none' io='native'/>
      <source dev='/dev/sdn'/>
      <target dev='vda' bus='virtio'/>
      <serial>4863707c-c62f-4e68-bbd0-76bc35952123</serial>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <disk type='block' device='disk'>
      <driver name='qemu' type='raw' cache='none' io='native'/>
      <source dev='/dev/cinder-volumes/6be19160-d8c8-45db-9c82-271e641c3710_disk.swap'/>
      <target dev='vdb' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </disk>
(...)

I am not sure what triggers how the swap device is then put as lvm into the cinder-volume group in detail (but I assume that this happens on libvirt level, not necessarily openstack level ??!). However, the nova code is at the end assuming the swap device under /var/lib/nova/instances/<uuid>/<uuid>_disk.swap. The entire resizing is not coming so far that it could be attempted to create a swap device on the target host as the error stops the resizing already with the failed attempted to 'scp' the swap device from the wrong place.

Analysis of the code alongside the stack trace in /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py (line 8024ff) shows that the 'real' swap device has no chance to be correctly recognized and handled:

                (...)
                # We will not copy over the swap disk here, and rely on
                # finish_migration to re-create it for us. This is ok because
                # the OS is shut down, and as recreating a swap disk is very
                # cheap it is more efficient than copying either locally or
                # over the n...

Read more...

Revision history for this message
Dr. Clemens Hardewig (bringha1) wrote :

Correction for code analysis of driver.py, 8024ff:

inst_base = /var/lib/nova/instances/<uuid>,
img_path = /dev/cinder-volumes/<uuid>_disk.swap,
fname = <uuid>_disk.swap
from_path = /var/lib/nova/instances/<uuid>_resize/<uuid>_disk.swap

uuid is the instance id each ...

Apologies

Revision history for this message
Dr. Clemens Hardewig (bringha1) wrote :

Here another suggestion for a fix:
As the last element for a fully working solution for my config, I extended the libvirt driver code in driver.py to make the lvm based swap volume deleted when the instance has been moved to the new host successfully:

In /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py line 1184ff, changes in _cleanup_resize have been made: Here the function in total with the marked extensions (---->):

def _cleanup_resize(self, context, instance, network_info):
        inst_base = libvirt_utils.get_instance_path(instance)
        target = inst_base + '_resize'

        if os.path.exists(target):
            # Deletion can fail over NFS, so retry the deletion as required.
            # Set maximum attempt as 5, most test can remove the directory
            # for the second time.
            utils.execute('rm', '-rf', target, delay_on_retry=True,
                          attempts=5)

        root_disk = self.image_backend.by_name(instance, 'disk')
        # TODO(nic): Set ignore_errors=False in a future release.
        # It is set to True here to avoid any upgrade issues surrounding
        # instances being in pending resize state when the software is updated;
        # in that case there will be no snapshot to remove. Once it can be
        # reasonably assumed that no such instances exist in the wild
        # anymore, it should be set back to False (the default) so it will
        # throw errors, like it should.
        if root_disk.exists():
            root_disk.remove_snap(libvirt_utils.RESIZE_SNAPSHOT_NAME,
                                  ignore_errors=True)

        # NOTE(mjozefcz):
        # self.image_backend.image for some backends recreates instance
        # directory and image disk.info - remove it here if exists
        # Do not remove inst_base for volume-backed instances since that
        # could potentially remove the files on the destination host
        # if using shared storage.
        if (os.path.exists(inst_base) and not root_disk.exists() and
                not compute_utils.is_volume_backed_instance(
                    context, instance)):
            try:
                shutil.rmtree(inst_base)
            except OSError as e:
                if e.errno != errno.ENOENT:
                    raise

        if instance.host != CONF.host:
            self._undefine_domain(instance)
            self.unplug_vifs(instance, network_info)
            self.unfilter_instance(instance, network_info)
-----> # (bringha) delete swap devices if lvm volumes
-----> # are used
-----> if CONF.libvirt.images_type == 'lvm':
-----> lvm.remove_volumes([lvmdisk for lvmdisk in self._lvm_disks(instance)
-----> if lvmdisk.endswith('.swap')])

Changing the code including the suggestions made in earlier comments on all compute nodes solved the problem for my config at least. I can now resize and migrate instances and the sending host is left clean. Might be that for an universal solution/other image_types something is missing still ....

Perhaps someone can put this in the official process for further review ...

Br br

summary: - Instance resize with swap on cinder volume fails
+ Instance resize with swap on lvm logical volume fails
Revision history for this message
Kurt Garloff (kgarloff) wrote :

Matt, do you need a pull request and gerrit to consider a fix for this?

Revision history for this message
Dr. Clemens Hardewig (bringha1) wrote :

Could someone of the Nova team please comment how to proceed with that topic.

Patching the code with each update of driver.py is not a very exciting way to handle this.

Thanks a lot

Br br

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

Fix proposed to branch: master
Review: https://review.openstack.org/618621

Changed in nova:
assignee: nobody → Dr. Clemens Hardewig (bringha1)
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Fix proposed to branch: master
Review: https://review.opendev.org/663986

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.opendev.org/663986

Lee Yarwood (lyarwood)
Changed in nova:
status: In Progress → New
importance: Undecided → Low
tags: added: lvm
tags: added: libvirt
tags: removed: volumes
Changed in nova:
status: New → Confirmed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.opendev.org/618621

Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.opendev.org/663986

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

Other bug subscribers

Remote bug watches

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