encrypted iSCSI volume fails to attach, name too long

[Anthony Lee]

When running the following tempest tests an error occurs in n-cpu:

tempest.scenario.test_encrypted_cinder_volumes.TestEncryptedCinderVolumes.test_encrypted_cinder_volumes_cryptsetup
test_encrypted_cinder_volumes_luks

This occurred when using devstack with nova at:

HEAD is now at d0c2684 Merge "libvirt: Resize down an instance booted from a volume"

Both stack traces below are from n-cpu logs:

Stack Trace (tempest.scenario.test_encrypted_cinder_volumes.TestEncryptedCinderVolumes.test_encrypted_cinder_volumes_cryptsetup):

2015-03-27 18:03:07.990 ERROR nova.compute.manager [req-cc941973-c038-4bac-a5ca-d516cd5dd33d TestEncryptedCinderVolumes-658052177 TestEncryptedCinderVolumes-1476988517] [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Failed to attach 2ab47be7-64ac-4d34-a38c-59c5e97e2ec2 at /dev/vdb
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Traceback (most recent call last):
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/compute/manager.py", line 4735, in _attach_volume
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] do_check_attach=False, do_driver_attach=True)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/virt/block_device.py", line 48, in wrapped
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] ret_val = method(obj, context, *args, **kwargs)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/virt/block_device.py", line 260, in attach
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] connector)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 85, in __exit__
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] six.reraise(self.type_, self.value, self.tb)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/virt/block_device.py", line 251, in attach
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] device_type=self['device_type'], encryption=encryption)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 1065, in attach_volume
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] self._disconnect_volume(connection_info, disk_dev)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 85, in __exit__
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] six.reraise(self.type_, self.value, self.tb)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 1052, in attach_volume
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] encryptor.attach_volume(context, **encryption)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/volume/encryptors/cryptsetup.py", line 86, in attach_volume
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] self._open_volume(passphrase, **kwargs)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/volume/encryptors/cryptsetup.py", line 71, in _open_volume
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] check_exit_code=True, run_as_root=True)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/opt/stack/new/nova/nova/utils.py", line 206, in execute
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] return processutils.execute(*cmd, **kwargs)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 233, in execute
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] cmd=sanitized_cmd)
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] ProcessExecutionError: Unexpected error while running command.
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup create --key-file=- --cipher aes-xts-plain64 --key-size 512 ip-10.52.1.17:3260-iscsi-iqn.2003-10.com.lefthandnetworks:ci-vsa-12-725:159016:volume-2ab47be7-64ac-4d34-a38c-59c5e97e2ec2-lun-0 /dev/sdb
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Exit code: 1
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Stdout: u''
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46] Stderr: u'Name "ip-10.52.1.17:3260-iscsi-iqn.2003-10.com.lefthandnetworks:ci-vsa-12-725:159016:volume-2ab47be7-64ac-4d34-a38c-59c5e97e2ec2-lun-0" too long.\n'
2015-03-27 18:03:07.990 29082 TRACE nova.compute.manager [instance: a2cccacf-2876-4e94-94e0-dbb3fbf51c46]

Stack Trace (test_encrypted_cinder_volumes_luks):

2015-03-27 18:06:48.928 ERROR nova.virt.libvirt.driver [req-7167f5a7-c620-474a-a6e0-1cc992192930 TestEncryptedCinderVolumes-658052177 TestEncryptedCinderVolumes-1476988517] [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Failed to attach volume at mountpoint: /dev/vdb
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Traceback (most recent call last):
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 1052, in attach_volume
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] encryptor.attach_volume(context, **encryption)
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] File "/opt/stack/new/nova/nova/volume/encryptors/luks.py", line 114, in attach_volume
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] self._open_volume(passphrase, **kwargs)
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] File "/opt/stack/new/nova/nova/volume/encryptors/luks.py", line 89, in _open_volume
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] run_as_root=True, check_exit_code=True)
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] File "/opt/stack/new/nova/nova/utils.py", line 206, in execute
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] return processutils.execute(*cmd, **kwargs)
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 233, in execute
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] cmd=sanitized_cmd)
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] ProcessExecutionError: Unexpected error while running command.
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup luksOpen --key-file=- /dev/sdb ip-10.52.1.17:3260-iscsi-iqn.2003-10.com.lefthandnetworks:ci-vsa-12-725:159021:volume-e74c95eb-e69b-4cf3-ac37-74e4ef38f796-lun-0
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Exit code: 1
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Stdout: u''
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a] Stderr: u'Name "ip-10.52.1.17:3260-iscsi-iqn.2003-10.com.lefthandnetworks:ci-vsa-12-725:159021:volume-e74c95eb-e69b-4cf3-ac37-74e4ef38f796-lun-0" too long.\n'
2015-03-27 18:06:48.928 29082 TRACE nova.virt.libvirt.driver [instance: ddeda0aa-1457-41d2-82e9-9a4ae888125a]

To reproduce, run the tempest tests mentioned above on system that has an ip, iscsi properties and volume name which, when combined, results in a very long name used by cryptsetup. The long name will cause the above error to occur.

[Sean Dague (sdague)]

This isn't really a dup, because this is about nova failing gracefully I think.

Can you provide relevant dmesg logs to figure out if this being triggered in the kernel or if this is something in cryptsetup itself, so that we can handle this in the right place?

[Matt Riedemann (mriedem)]

Bug 1432490 is related and sounds like it's a user/config error. Nova could parse stderr though and raise a more useful error in this case. I can't find any docs on the max name length for cryptsetup which leads me to believe it's kernel-specific so nova would just have to catch the ProcessExecutionError and parse stderr to see if that's the issue to give a more useful nova exception back.

[Sean Dague (sdague)]

It appears that dm-crypt only handles device names <= 127 characters in length, the above it 129 characters. libvirt should probably have handling code to fail fast if the device name is never going to work.

[Sean Dague (sdague)]

Marked low-hanging-fruit because this should be fixed on the nova side solely by creating a well understood error path here.

[Walt Boring (walter-boring)]

Nova has the volume uuid at the time when the crypt name is used. You could simply use the volume uuid as the crypt name in this case it would always be less than 127 characters.

[Nha Pham (phqnha)]

If I change the dev_name using the uuid, does it affect any other function?

[Nha Pham (phqnha)]

I mean, does it break the contract with other parts openstack. For example, cinder always uses the dev_name formed by this:

        # a unique name for the volume -- e.g., the iSCSI participant name
        self.dev_name = self.symlink_path.split('/')[-1]
        # the device's actual path on the compute host -- e.g., /dev/sd_
        self.dev_path = os.path.realpath(self.symlink_path)

[OpenStack Infra (hudson-openstack)]

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

[lvmxh (shaohef)]

hi Sean:

I have not checked the kernel code.
I just try it on my Ubuntu 14.04

It seams it is OK device names <= 128 characters in length.

$ wc -c <<< $DMNANE129
129
$ wc -c <<< $DMNANE128
128

$ sudo cryptsetup create --key-file=- --cipher aes-xts-plain64 --key-size 512 $DMNANE129 /dev/loop0
Name "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaddd" too long.

$ sudo cryptsetup create --key-file=- --cipher aes-xts-plain64 --key-size 512 $DMNANE128 /dev/loop0
Enter passphrase: Error reading passphrase from terminal

[lvmxh (shaohef)]

declaration：

Enter passphrase: Error reading passphrase from terminal

for I stop to input the "Enter passphrase".

[Ramy Asselin (ramy-asselin)]

I tried out the patch with our driver on our internal ci system. It gets past the iqn too long error, but is failing still. n-cpu logs attached here.

[Ramy Asselin (ramy-asselin)]

My comment #11 is for patch set #1 ^^.
I see now there are new patch sets. I will run those too.

[Ramy Asselin (ramy-asselin)]

Adding n-cpu log for patch set #7 (run on internal ci) which passed tempest test_encrypted_cinder_volumes_cryptsetup & test_encrypted_cinder_volumes_luks. Previously this cinder driver failed with iqn too long.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Michael Still (<email address hidden>) on branch: master
Review: https://review.openstack.org/174656
Reason: This patch has been sitting unchanged for more than 12 weeks. I am therefore going to abandon it to keep the nova review queue sane. Please feel free to restore the change if you're still working on it.

[Matt Riedemann (mriedem)]

Fixing this on master (pike) now would mean fixing this in the os-brick library since Nova no longer has this code in tree:

https://github.com/openstack/nova/commit/9c23cdc247770830fa288f429ca7231eb431a3b2

[Matt Riedemann (mriedem)]

The patch that is abandoned would work as long as we handle both old and new style naming conventions so we can straddle upgrades, like in this fix:

https://github.com/openstack/nova/commit/89a61ab8f4602e018763afb173e1a862f151a222