yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1688166] [NEW] Missing rootwrap filter for cryptsetup

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Jackie Truong <1688166@xxxxxxxxxxxxxxxxxx>
Date: Thu, 04 May 2017 03:04:21 -0000
Reply-to: Bug 1688166 <1688166@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Description
===========
`cryptsetup` is not authorized to run with root permissions. The rootwrap filter for cryptsetup was recently removed from compute.filters [1], but it is still needed by dmcrypt [2].

References:
[1] https://github.com/openstack/nova/commit/9c23cdc247770830fa288f429ca7231eb431a3b2#diff-b01672c9be31a4fe1dd0921241a7ae15L234

[2]
https://github.com/openstack/nova/blob/master/nova/virt/libvirt/storage/dmcrypt.py


Steps to reproduce
==================

1. Set up an LVM device:
Create a backing file:
  $ truncate nova-lvm -s 2G

Mount the backing file on a loop device:
  $ sudo losetup /dev/loop1 nova-lvm

Prepare the device for LVM:
  $ sudo pvcreate /dev/loop1

Create the LVM group on the loop device:
  $ sudo vgcreate nova-lvm /dev/loop1

2. Set up a devstack environment with ephemeral storage encryption enabled by adding the following lines to `lib/nova`:
  iniset $NOVA_CONF ephemeral_storage_encryption enabled "True"
  iniset $NOVA_CONF ephemeral_storage_encryption cipher "aes-xts-plain64"
  iniset $NOVA_CONF ephemeral_storage_encryption key_size "256"
  iniset $NOVA_CONF libvirt images_type "lvm"
  iniset $NOVA_CONF libvirt images_volume_group "nova-lvm"

3. Stack:
  $ ./stack

4. Use Nova to boot an instance:
  $ nova boot --flavor 1 --image {image_id}

---OR---

4. Run Barbican Tempest tests:

4a. Set up a Tempest environment:
  $ pip install virtualenv
  $ mkdir tempest-env
  $ virtualenv tempest-env
  $ cd tempest-env
  $ source bin/activate

4b. Install Tempest:
  $ git clone http://git.openstack.org/openstack/tempest
  $ bin/pip install tempest/

4c. Install the Barbican Tempest plugin and oslotest:
  $ git clone https://git.openstack.org/openstack/barbican-tempest-plugin
  $ bin/pip install -e barbican-tempest-plugin/
  $ bin/pip install oslotest

4d. Run Barbican Tempest tests
  $ testr run barbican_tempest_plugin


Expected result
===============
Instance successfully boots.


Actual result
=============
Instance fails to boot.

Example traceback (from `gate-barbican-simple-crypto-dsvm-tempest-
ubuntu-xenial-nv` [1]):

2017-04-30 16:17:41.576206 | Captured traceback:
2017-04-30 16:17:41.576224 | ~~~~~~~~~~~~~~~~~~~
2017-04-30 16:17:41.576246 |     Traceback (most recent call last):
2017-04-30 16:17:41.576272 |       File "tempest/test.py", line 96, in wrapper
2017-04-30 16:17:41.576298 |         return f(self, *func_args, **func_kwargs)
2017-04-30 16:17:41.576362 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/barbican_tempest_plugin/tests/scenario/test_image_signing.py", line 48, in test_signed_image_upload_and_boot
2017-04-30 16:17:41.576382 |         wait_until='ACTIVE')
2017-04-30 16:17:41.576437 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/barbican_tempest_plugin/tests/scenario/manager.py", line 201, in create_server
2017-04-30 16:17:41.576460 |         image_id=image_id, **kwargs)
2017-04-30 16:17:41.576492 |       File "tempest/common/compute.py", line 206, in create_test_server
2017-04-30 16:17:41.576510 |         server['id'])
2017-04-30 16:17:41.576557 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-04-30 16:17:41.576577 |         self.force_reraise()
2017-04-30 16:17:41.576626 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-04-30 16:17:41.576652 |         six.reraise(self.type_, self.value, self.tb)
2017-04-30 16:17:41.576683 |       File "tempest/common/compute.py", line 188, in create_test_server
2017-04-30 16:17:41.576711 |         clients.servers_client, server['id'], wait_until)
2017-04-30 16:17:41.576742 |       File "tempest/common/waiters.py", line 76, in wait_for_server_status
2017-04-30 16:17:41.576762 |         server_id=server_id)
2017-04-30 16:17:41.576809 |     tempest.exceptions.BuildErrorException: Server b2fc6277-1f92-4466-a177-194fa7e8f0c3 failed to build and is in ERROR status
2017-04-30 16:17:41.576926 |     Details: {u'message': u"Build of instance b2fc6277-1f92-4466-a177-194fa7e8f0c3 aborted: Unexpected error while running command.\nCommand: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt\nExit code: 99\nStdout: u''\nStder", u'created': u'2017-04-30T16:16:50Z', u'code': 500}


n-cpu log [2] indicates that cryptsetup is an unauthorized command:


2017-04-30 16:16:43.530 19568 ERROR nova.virt.libvirt.storage.dmcrypt [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] Could not disconnect encrypted volume b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt. If dm-crypt device is still active it will have to be destroyed manually for cleanup to succeed.
2017-04-30 16:16:43.532 19568 ERROR root [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] Original exception being dropped: ['Traceback (most recent call last):\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 745, in remove_volume_on_error\n    yield\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 735, in create_image\n    create_lvm_image(base, size)\n', '  File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner\n    return f(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 693, in create_lvm_image\n    encrypt_lvm_image()\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 680, in encrypt_lvm_image\n    key)\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 64, in create_volume\n    key = \'\'.join(map(lambda byte: "%02x" % byte, key))\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 64, in <lambda>\n    key = \'\'.join(map(lambda byte: "%02x" % byte, key))\n', 'TypeError: %x format: a number is required, not str\n']
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Instance failed to spawn
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Traceback (most recent call last):
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2122, in _build_resources
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     yield resources
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/compute/manager.py", line 1927, in _build_and_run_instance
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     block_device_info=block_device_info)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2688, in spawn
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     block_device_info=block_device_info)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3095, in _create_image
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     fallback_from_host)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3211, in _create_and_inject_local_root
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     instance, size, fallback_from_host)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 6780, in _try_fetch_image_cache
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     size=size)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 227, in cache
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     *args, **kwargs)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 735, in create_image
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     create_lvm_image(base, size)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/lib/python2.7/contextlib.py", line 35, in __exit__
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     self.gen.throw(type, value, traceback)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 751, in remove_volume_on_error
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     dmcrypt.delete_volume(path.rpartition('/')[2])
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 92, in delete_volume
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     "cleanup to succeed."), {'volume': target})
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     self.force_reraise()
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     six.reraise(self.type_, self.value, self.tb)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 79, in delete_volume
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     utils.execute('cryptsetup', 'remove', target, run_as_root=True)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/utils.py", line 48, in execute
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return utils.execute(*args, **kwargs)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/utils.py", line 297, in execute
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return RootwrapProcessHelper().execute(*cmd, **kwargs)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/utils.py", line 180, in execute
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return processutils.execute(*cmd, **kwargs)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 400, in execute
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     cmd=sanitized_cmd)
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] ProcessExecutionError: Unexpected error while running command.
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Exit code: 99
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Stdout: u''
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Stderr: u'/usr/local/bin/nova-rootwrap: Unauthorized command: cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt (no filter matched)\n'
2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]

[1] http://logs.openstack.org/59/455459/17/check/gate-barbican-simple-crypto-dsvm-tempest-ubuntu-xenial-nv/26e8659/console.html#_2017-04-30_16_17_41_576206
[2] http://logs.openstack.org/59/455459/17/check/gate-barbican-simple-crypto-dsvm-tempest-ubuntu-xenial-nv/26e8659/logs/screen-n-cpu.txt.gz#_2017-04-30_16_16_43_532


Environment
===========
Latest `master` branch for all projects (including nova, castellan, and barbican), except for barbican-tempest-plugin (which has a patch [1] applied so that we can get past the error addressed by the patch).

[1] https://review.openstack.org/#/c/446072/


Notes
=====
You will notice a TypeError in the n-cpu log output - I plan on reporting a separate bug for that.

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1688166

Title:
  Missing rootwrap filter for cryptsetup

Status in OpenStack Compute (nova):
  New

Bug description:
  Description
  ===========
  `cryptsetup` is not authorized to run with root permissions. The rootwrap filter for cryptsetup was recently removed from compute.filters [1], but it is still needed by dmcrypt [2].

  References:
  [1] https://github.com/openstack/nova/commit/9c23cdc247770830fa288f429ca7231eb431a3b2#diff-b01672c9be31a4fe1dd0921241a7ae15L234

  [2]
  https://github.com/openstack/nova/blob/master/nova/virt/libvirt/storage/dmcrypt.py

  
  Steps to reproduce
  ==================

  1. Set up an LVM device:
  Create a backing file:
    $ truncate nova-lvm -s 2G

  Mount the backing file on a loop device:
    $ sudo losetup /dev/loop1 nova-lvm

  Prepare the device for LVM:
    $ sudo pvcreate /dev/loop1

  Create the LVM group on the loop device:
    $ sudo vgcreate nova-lvm /dev/loop1

  2. Set up a devstack environment with ephemeral storage encryption enabled by adding the following lines to `lib/nova`:
    iniset $NOVA_CONF ephemeral_storage_encryption enabled "True"
    iniset $NOVA_CONF ephemeral_storage_encryption cipher "aes-xts-plain64"
    iniset $NOVA_CONF ephemeral_storage_encryption key_size "256"
    iniset $NOVA_CONF libvirt images_type "lvm"
    iniset $NOVA_CONF libvirt images_volume_group "nova-lvm"

  3. Stack:
    $ ./stack

  4. Use Nova to boot an instance:
    $ nova boot --flavor 1 --image {image_id}

  ---OR---

  4. Run Barbican Tempest tests:

  4a. Set up a Tempest environment:
    $ pip install virtualenv
    $ mkdir tempest-env
    $ virtualenv tempest-env
    $ cd tempest-env
    $ source bin/activate

  4b. Install Tempest:
    $ git clone http://git.openstack.org/openstack/tempest
    $ bin/pip install tempest/

  4c. Install the Barbican Tempest plugin and oslotest:
    $ git clone https://git.openstack.org/openstack/barbican-tempest-plugin
    $ bin/pip install -e barbican-tempest-plugin/
    $ bin/pip install oslotest

  4d. Run Barbican Tempest tests
    $ testr run barbican_tempest_plugin

  
  Expected result
  ===============
  Instance successfully boots.

  
  Actual result
  =============
  Instance fails to boot.

  Example traceback (from `gate-barbican-simple-crypto-dsvm-tempest-
  ubuntu-xenial-nv` [1]):

  2017-04-30 16:17:41.576206 | Captured traceback:
  2017-04-30 16:17:41.576224 | ~~~~~~~~~~~~~~~~~~~
  2017-04-30 16:17:41.576246 |     Traceback (most recent call last):
  2017-04-30 16:17:41.576272 |       File "tempest/test.py", line 96, in wrapper
  2017-04-30 16:17:41.576298 |         return f(self, *func_args, **func_kwargs)
  2017-04-30 16:17:41.576362 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/barbican_tempest_plugin/tests/scenario/test_image_signing.py", line 48, in test_signed_image_upload_and_boot
  2017-04-30 16:17:41.576382 |         wait_until='ACTIVE')
  2017-04-30 16:17:41.576437 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/barbican_tempest_plugin/tests/scenario/manager.py", line 201, in create_server
  2017-04-30 16:17:41.576460 |         image_id=image_id, **kwargs)
  2017-04-30 16:17:41.576492 |       File "tempest/common/compute.py", line 206, in create_test_server
  2017-04-30 16:17:41.576510 |         server['id'])
  2017-04-30 16:17:41.576557 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
  2017-04-30 16:17:41.576577 |         self.force_reraise()
  2017-04-30 16:17:41.576626 |       File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2017-04-30 16:17:41.576652 |         six.reraise(self.type_, self.value, self.tb)
  2017-04-30 16:17:41.576683 |       File "tempest/common/compute.py", line 188, in create_test_server
  2017-04-30 16:17:41.576711 |         clients.servers_client, server['id'], wait_until)
  2017-04-30 16:17:41.576742 |       File "tempest/common/waiters.py", line 76, in wait_for_server_status
  2017-04-30 16:17:41.576762 |         server_id=server_id)
  2017-04-30 16:17:41.576809 |     tempest.exceptions.BuildErrorException: Server b2fc6277-1f92-4466-a177-194fa7e8f0c3 failed to build and is in ERROR status
  2017-04-30 16:17:41.576926 |     Details: {u'message': u"Build of instance b2fc6277-1f92-4466-a177-194fa7e8f0c3 aborted: Unexpected error while running command.\nCommand: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt\nExit code: 99\nStdout: u''\nStder", u'created': u'2017-04-30T16:16:50Z', u'code': 500}


  n-cpu log [2] indicates that cryptsetup is an unauthorized command:

  
  2017-04-30 16:16:43.530 19568 ERROR nova.virt.libvirt.storage.dmcrypt [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] Could not disconnect encrypted volume b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt. If dm-crypt device is still active it will have to be destroyed manually for cleanup to succeed.
  2017-04-30 16:16:43.532 19568 ERROR root [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] Original exception being dropped: ['Traceback (most recent call last):\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 745, in remove_volume_on_error\n    yield\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 735, in create_image\n    create_lvm_image(base, size)\n', '  File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner\n    return f(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 693, in create_lvm_image\n    encrypt_lvm_image()\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 680, in encrypt_lvm_image\n    key)\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 64, in create_volume\n    key = \'\'.join(map(lambda byte: "%02x" % byte, key))\n', '  File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 64, in <lambda>\n    key = \'\'.join(map(lambda byte: "%02x" % byte, key))\n', 'TypeError: %x format: a number is required, not str\n']
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [req-2dcb6768-1edc-4ac7-b00d-7d081478abef tempest-ImageSigningTest-57730532 tempest-ImageSigningTest-57730532] [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Instance failed to spawn
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Traceback (most recent call last):
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2122, in _build_resources
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     yield resources
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/compute/manager.py", line 1927, in _build_and_run_instance
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     block_device_info=block_device_info)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 2688, in spawn
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     block_device_info=block_device_info)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3095, in _create_image
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     fallback_from_host)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3211, in _create_and_inject_local_root
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     instance, size, fallback_from_host)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 6780, in _try_fetch_image_cache
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     size=size)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 227, in cache
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     *args, **kwargs)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 735, in create_image
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     create_lvm_image(base, size)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/lib/python2.7/contextlib.py", line 35, in __exit__
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     self.gen.throw(type, value, traceback)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/imagebackend.py", line 751, in remove_volume_on_error
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     dmcrypt.delete_volume(path.rpartition('/')[2])
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 92, in delete_volume
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     "cleanup to succeed."), {'volume': target})
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     self.force_reraise()
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     six.reraise(self.type_, self.value, self.tb)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/storage/dmcrypt.py", line 79, in delete_volume
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     utils.execute('cryptsetup', 'remove', target, run_as_root=True)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/virt/libvirt/utils.py", line 48, in execute
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return utils.execute(*args, **kwargs)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/utils.py", line 297, in execute
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return RootwrapProcessHelper().execute(*cmd, **kwargs)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/opt/stack/new/nova/nova/utils.py", line 180, in execute
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     return processutils.execute(*cmd, **kwargs)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]   File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/processutils.py", line 400, in execute
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]     cmd=sanitized_cmd)
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] ProcessExecutionError: Unexpected error while running command.
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Exit code: 99
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Stdout: u''
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3] Stderr: u'/usr/local/bin/nova-rootwrap: Unauthorized command: cryptsetup remove b2fc6277-1f92-4466-a177-194fa7e8f0c3_disk-dmcrypt (no filter matched)\n'
  2017-04-30 16:16:43.532 19568 ERROR nova.compute.manager [instance: b2fc6277-1f92-4466-a177-194fa7e8f0c3]

  [1] http://logs.openstack.org/59/455459/17/check/gate-barbican-simple-crypto-dsvm-tempest-ubuntu-xenial-nv/26e8659/console.html#_2017-04-30_16_17_41_576206
  [2] http://logs.openstack.org/59/455459/17/check/gate-barbican-simple-crypto-dsvm-tempest-ubuntu-xenial-nv/26e8659/logs/screen-n-cpu.txt.gz#_2017-04-30_16_16_43_532

  
  Environment
  ===========
  Latest `master` branch for all projects (including nova, castellan, and barbican), except for barbican-tempest-plugin (which has a patch [1] applied so that we can get past the error addressed by the patch).

  [1] https://review.openstack.org/#/c/446072/

  
  Notes
  =====
  You will notice a TypeError in the n-cpu log output - I plan on reporting a separate bug for that.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1688166/+subscriptions
Follow ups

[Bug 1688166] Re: Missing rootwrap filter for cryptsetup
From: OpenStack Infra, 2017-05-18