Bug 1479751

Hi!

https://rhos-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/RHOS/view/RHOS12/job/OT_container_netiso_osp12_HA_SSL_localregistry_full_tempest/40/testReport/tempest.scenario.test_volume_boot_pattern/TestVolumeBootPattern/test_boot_server_from_encrypted_volume_luks_compute_id_cb78919a_e553_4bab_b73b_10cf4d2eb125_volume_/

Reproduced again in last puddle OpenStack-12.0-RHEL-7-20170818.3

reproduced
https://rhos-jenkins.rhev-ci-vms.eng.rdu2.redhat.com/view/RHOS/view/RHOS12/job/OT_container_netiso_osp12_HA_SSL_localregistry_full_tempest/51/testReport/tempest.scenario.test_volume_boot_pattern/TestVolumeBootPattern/test_boot_server_from_encrypted_volume_luks_compute_id_cb78919a_e553_4bab_b73b_10cf4d2eb125_volume_/

Neither of the two recent failures show signs of the "Key manager error" that has been fixed, so I wonder if the failures are due to bug #1478161. The failure reported in comment #4 contains the "keymgr.fixed_key not defined" string associated with the other bz. I don't know what happened in the comment #5 failure.

On version:
puppet-tripleo-7.4.1-0.20170925173839.bc3dfc5

This still fails but it looks as due to deployment/network issue. 
I'll debug and update once I figure it out. 

2017-10-02 12:45:28.267 18515 ERROR tempest.test     raise exceptions.Conflict(resp_body, resp=resp)
2017-10-02 12:45:28.267 18515 ERROR tempest.test Conflict: An object with that identifier already exists
2017-10-02 12:45:28.267 18515 ERROR tempest.test Details: {u'message': u'Unable to complete operation on subnet 2bdf6188-22be-4a2e-8516-f0d21079d98b: One or more ports have an IP allocation from this subnet.', u'type': u'SubnetInUse', u'detail': u''}
2017-10-02 12:45:28.267 18515 ERROR tempest.test

Odd I've set fixed_key on Cinder.conf. 
Also on nova.conf on compute node, do I need to set on Nova api server as well? 

As I still fail and getting ->  fixed_key not defined'

Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/common/utils/__init__.py", line 89, in wrapper
    return f(self, *func_args, **func_kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/test_volume_boot_pattern.py", line 232, in test_boot_server_from_encrypted_volume_luks
    delete_on_termination=False)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/test_volume_boot_pattern.py", line 70, in _boot_instance_from_resource
    return self.create_server(image_id='', **create_kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/manager.py", line 205, in create_server
    image_id=image_id, **kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/common/compute.py", line 256, in create_test_server
    server['id'])
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
    self.force_reraise()
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
    six.reraise(self.type_, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/tempest/common/compute.py", line 227, in create_test_server
    clients.servers_client, server['id'], wait_until)
  File "/usr/lib/python2.7/site-packages/tempest/common/waiters.py", line 76, in wait_for_server_status
    server_id=server_id)
tempest.exceptions.BuildErrorException: Server 1d5c363c-844a-4549-b0a1-a10aa2982113 failed to build and is in ERROR status
Details: {u'message': u'Build of instance 1d5c363c-844a-4549-b0a1-a10aa2982113 aborted: keymgr.fixed_key not defined', u'code': 500, u'created': u'2017-10-23T10:04:42Z'}
Ran 1 tests in 340.301s
FAILED (id=2, failures=1)

Tzach,

I looked at the system you left for me (thank you!), and the problem is clear. On the nova side, it's the nova-compute service that handles encrypted volumes. It looks like the Key Manager is properly set to match Cinder's Key Manager, but the fixed_key is *not* set.

One thing to bear in mind is Nova is containerized, and so it's necessary for the fixed_key to appear in the nova_compute container. I have no idea how Tempest configures things, but the required setting is definitely missing.

Here's what I'm seeing:

[root@compute-0 ~]# docker exec -ti nova_compute bash -c "grep fixed_key /etc/nova/*.conf"
/etc/nova/nova.conf:#fixed_key=<None>

OK I think I resolved the missing fixed_key. 
I updated wrong location of nova.conf file on compute node. 
Looks a little better yet still failing. 


traceback-1: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/utils/test_utils.py", line 84, in call_and_ignore_notfound_exc
    return func(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/lib/services/volume/v2/volumes_client.py", line 136, in delete_volume
    resp, body = self.delete(url)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 301, in delete
    return self.request('DELETE', url, extra_headers, headers, body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/services/volume/base_client.py", line 38, in request
    method, url, extra_headers, headers, body, chunked)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 659, in request
    self._error_checker(resp, resp_body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 770, in _error_checker
    raise exceptions.BadRequest(resp_body, resp=resp)
tempest.lib.exceptions.BadRequest: Bad request
Details: {u'message': u'Invalid volume: Volume status must be available or error or error_restoring or error_extending or error_managing and must not be migrating, attached, belong to a group, have snapshots or be disassociated from snapshots after volume transfer.', u'code': 400}
}}}

traceback-2: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 871, in wait_for_resource_deletion
    raise exceptions.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (TestVolumeBootPattern:_run_cleanups) Failed to delete volume ff82f075-7c06-4a21-8cea-cf01d2d3bd58 within the required time (300 s).
}}}

traceback-3: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/lib/services/volume/v2/types_client.py", line 88, in delete_volume_type
    resp, body = self.delete("types/%s" % volume_type_id)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 301, in delete
    return self.request('DELETE', url, extra_headers, headers, body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 659, in request
    self._error_checker(resp, resp_body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 770, in _error_checker
    raise exceptions.BadRequest(resp_body, resp=resp)
tempest.lib.exceptions.BadRequest: Bad request
Details: {u'message': u'Target volume type is still in use.', u'code': 400}
}}}

Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/common/utils/__init__.py", line 89, in wrapper
    return f(self, *func_args, **func_kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/test_volume_boot_pattern.py", line 232, in test_boot_server_from_encrypted_volume_luks
    delete_on_termination=False)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/test_volume_boot_pattern.py", line 70, in _boot_instance_from_resource
    return self.create_server(image_id='', **create_kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/scenario/manager.py", line 205, in create_server
    image_id=image_id, **kwargs)
  File "/usr/lib/python2.7/site-packages/tempest/common/compute.py", line 256, in create_test_server
    server['id'])
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
    self.force_reraise()
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
    six.reraise(self.type_, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/tempest/common/compute.py", line 227, in create_test_server
    clients.servers_client, server['id'], wait_until)
  File "/usr/lib/python2.7/site-packages/tempest/common/waiters.py", line 96, in wait_for_server_status
    raise lib_exc.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (TestVolumeBootPattern:test_boot_server_from_encrypted_volume_luks) Server 385abe20-0f07-44f4-9289-33c76c0f73ba failed to reach ACTIVE status and task state "None" within the required time (300 s). Current status: BUILD. Current task state: spawning.
======================================================================
FAIL: tearDownClass (tempest.scenario.test_volume_boot_pattern.TestVolumeBootPattern)
tags: worker-0
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/tempest/test.py", line 190, in tearDownClass
    six.reraise(etype, value, trace)
  File "/usr/lib/python2.7/site-packages/tempest/test.py", line 173, in tearDownClass
    teardown()
  File "/usr/lib/python2.7/site-packages/tempest/test.py", line 477, in clear_credentials
    cls._creds_provider.clear_creds()
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/dynamic_creds.py", line 445, in clear_creds
    self._clear_isolated_net_resources()
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/dynamic_creds.py", line 436, in _clear_isolated_net_resources
    creds.subnet['name'])
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/dynamic_creds.py", line 386, in _clear_isolated_subnet
    client.delete_subnet(subnet_id)
  File "/usr/lib/python2.7/site-packages/tempest/lib/services/network/subnets_client.py", line 52, in delete_subnet
    return self.delete_resource(uri)
  File "/usr/lib/python2.7/site-packages/tempest/lib/services/network/base.py", line 41, in delete_resource
    resp, body = self.delete(req_uri)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 301, in delete
    return self.request('DELETE', url, extra_headers, headers, body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 659, in request
    self._error_checker(resp, resp_body)
  File "/usr/lib/python2.7/site-packages/tempest/lib/common/rest_client.py", line 780, in _error_checker
    raise exceptions.Conflict(resp_body, resp=resp)
tempest.lib.exceptions.Conflict: An object with that identifier already exists
Details: {u'message': u'Unable to complete operation on subnet cc3fa5bb-3f7b-45b0-a23d-2849a7981a76: One or more ports have an IP allocation from this subnet.', u'type': u'SubnetInUse', u'detail': u''}
Ran 2 tests in 931.134s (+11.121s)
FAILED (id=4, failures=2)

OK, lots of ground to cover. I signed onto Tzach's system and report the following:

1) The original "Key manager error" has been solved because the api_class is now being properly set in the key_manager section of /etc/cinder/cinder.conf and /etc/nova/nova.conf.

2) The "keymgr.fixed_key not defined" remains an issue, and updates should be tracked in bug #1478161

3) I do not know why Tzach's attempt to manually run the test with the fixed_key patched into the nova_compute container didn't work (comment #13).

- The primary error is this one

tempest.lib.exceptions.TimeoutException: Request timed out
Details: (TestVolumeBootPattern:test_boot_server_from_encrypted_volume_luks) Server 385abe20-0f07-44f4-9289-33c76c0f73ba failed to reach ACTIVE status and task state "None" within the required time (300 s). Current status: BUILD. Current task state: spawning.

- I signed onto the container, and see that nova_compute was able to access the encrypted volume, and both cinder and nova show the volume is attached. I do not know why the test timed out.

4) We still need to determine why the fixed_key isn't properly set in the nova configuration when the tests are run by CI. While it would be interesting to see the test pass after manually patching in the key, the real solution will be making sure the fix_key is set automatically.

Reccomendations:

- Close this BZ because the "Key manager error" has been resolved.
- Track the "keymgr.fixed_key not defined" issue in bug #1478161.
- As Lee pointed out in bug #1478161 comment #15 this is not a nova issue, so I'm not sure who should be the assignee. I took a stab at trying to understand the overcloud deployment, and what sort of post-deployment configurations steps are made, but it's beyond me. Things like the fixed_key are not configurable via TripleO, so something must be responsible for configuring the encryption settings. I just don't know what does that in this CI job.

The failures once fixed_key is configured might be related to bug #1487920 where we are seeing luksOpen calls hang within the n-cpu container. I'm going to close bug #1478161 out in favour of bug #1487920 as the fixed_key issue isn't something openstack-nova should handle.

Notice #16, setting depends on 1487920
As we shouldn't retest/verify before that one lands.

Created attachment 1353340 [details]
Testdir

Verified on:
openstack-tripleo-heat-templates-7.0.3-0.20171024200825.el7ost.noarch

The test passed without issue. 

I did however have to switch from LVM to other Cinder backend (xtremio).
As my LVM was too small 10G, kept failing to create Cinder volumes due to LVM. 
Once I switched Cinder backend test passed without issue.

See #20, forgot to change status to verified.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2017:3462