[9.x][BVT] Deployment fails on execution of task openstack-network-networks

[Roman Podoliaka]

9.x BVT builds currently fail with the following traceback:

2016-11-22 07:41:12 - ERROR decorators.py:126 -- Traceback (most recent call last):
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 120, in wrapper
    result = func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/tests/test_ceph.py", line 507, in ceph_rados_gw
    self.fuel_web.deploy_cluster_wait(cluster_id)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 460, in wrapper
    result = func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 445, in wrapper
    result = func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 496, in wrapper
    return func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 503, in wrapper
    result = func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/helpers/decorators.py", line 387, in wrapper
    return func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/models/fuel_web_client.py", line 953, in deploy_cluster_wait
    self.assert_task_success(task, interval=interval, timeout=timeout)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/core/helpers/log_helpers.py", line 215, in wrapped
    result = func(*args, **kwargs)
  File "/home/jenkins/workspace/9.x.main.ubuntu.bvt_2/fuelweb_test/models/fuel_web_client.py", line 354, in assert_task_success
    task["name"], task['status'], 'ready', _message(task)
  File "/home/jenkins/venv-nailgun-tests-2.9/local/lib/python2.7/site-packages/proboscis/asserts.py", line 55, in assert_equal
    raise ASSERTION_ERROR(message)
AssertionError: Task 'deploy' has incorrect status. error != ready, 'Deployment has failed. All nodes are finished. Failed tasks: Task[openstack-network-networks/1] Stopping the deployment process!'

e.g. https://product-ci.infra.mirantis.net/job/9.x.main.ubuntu.bvt_2/541/ or https://product-ci.infra.mirantis.net/job/9.x.main.ubuntu.bvt_2/542/

this is due to the fact neutrona-api responds with 503:

503 Service Unavailable

The server is currently unavailable. Please try again at a later time.

Neutron server returns request_ids: ['req-bfc16ecf-900f-4557-8bc6-53ba0ae6ee8e']". Retrying for 4 sec.

which is caused by keystone-api returning 401:

2016-11-22 07:39:14.140 6560 DEBUG keystoneauth.session [-] Request returned failure status: 401 request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:466
2016-11-22 07:39:14.141 6560 WARNING keystonemiddleware.auth_token [-] Identity response: {"error": {"message": "The request you have made requires authentication.", "code":
 401, "title": "Unauthorized"}}
2016-11-22 07:39:14.142 6560 CRITICAL keystonemiddleware.auth_token [-] Unable to validate token: Identity server rejected authorization necessary to fetch token data
2016-11-22 07:39:14.144 6560 INFO neutron.wsgi [-] 10.109.6.9 - - [22/Nov/2016 07:39:14] "GET /v2.0/subnets.json HTTP/1.1" 503 320 0.079793

which is caused by the fact domain Default does not exist:

2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers [req-60f61022-4ad8-4d0a-9e6e-62543fa8cd7a - - - - -] Could not find domain: Default
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers Traceback (most recent call last):
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/keystone/auth/controllers.py", line 187, in _lookup_domain
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers domain_ref = self.resource_api.get_domain(domain_id)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/keystone/common/manager.py", line 124, in wrapped
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers __ret_val = __f(*args, **kwargs)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/cache/region.py", line 1053, in decorate
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers should_cache_fn)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/cache/region.py", line 657, in get_or_create
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers async_creator) as value:
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/core/dogpile.py", line 158, in __enter__
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers return self._enter()
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/core/dogpile.py", line 98, in _enter
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers generated = self._enter_create(createdtime)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/core/dogpile.py", line 149, in _enter_create
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers created = self.creator()
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/cache/region.py", line 625, in gen_value
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers created_value = creator()
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/dogpile/cache/region.py", line 1049, in creator
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers return fn(*arg, **kw)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers File "/usr/lib/python2.7/dist-packages/keystone/resource/core.py", line 706, in get_domain
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers raise exception.DomainNotFound(domain_id=domain_id)
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers DomainNotFound: Could not find domain: Default
2016-11-22 09:08:17.648 23030 ERROR keystone.auth.controllers
2016-11-22 09:08:17.651 23030 WARNING keystone.common.wsgi [req-60f61022-4ad8-4d0a-9e6e-62543fa8cd7a - - - - -] Authorization failed. The request you have made requires authentication. from 10.109.6.9
2016-11-22 09:08:23.703 23031 DEBUG keystone.middleware.auth [req-83459e6a-518f-4641-9585-29c7391dd851 - - - - -] There is either no auth token in the request or the certificate issuer is not trusted. No auth context will be set. _build_auth_context /usr/lib/python2.7/dist-packages/keystone/middleware/auth.py:71

[Roman Podoliaka (rpodolyaka)]

Ok, so domain actually exists, but it's id is `default` not `Default`:

http://paste.openstack.org/show/590021/

When I change the case in neutron.conf and restart neutron-server it starts working correctly.

I checked my config on 9.0 environment and looks like it *used to* work with both lower case and upper case value there.

So at this point my understanding is that something changed in Keystone and now the look up is case sensitive.

[Boris Bobrov (bbobrov)]

Some time ago we merged https://review.openstack.org/#/c/379905/. Yesterday it was merged to our 9.0 branch. The patch added an additional check of domain_id.

We cannot revert it, because the issue without the check is more severe. We should fix neutron.conf. Now it looks like this:

 user_domain_id=Default
 project_domain_id=Default

The best fix would be to switch from domain_id to domain_name:

 user_domain_name=Default
 project_domain_name=Default

Second best fix (if the best doesn't help) is to switch domain_id to lowercase:

 user_domain_id=default
 project_domain_id=default

[Nikita Karpin (mkarpin)]

fix - https://review.openstack.org/#/c/400672/

[Nikita Karpin (mkarpin)]

fix merged

[Ekaterina Shutova (eshutova)]

Verified on 9.2 snapshot 553.
Problem is fixed, test passed.