keystone provisioning failed on mainline build 2727

[Vedamurthy Joshi]

Build : BaseFlowTest

Openstack provisioning failed on this HA setup :

http://anamika.englab.juniper.net:8080/job/ubuntu-14-04_juno_tor_Multi_Node_Sanity/18/console

2016-03-28 12:17:28:293315: Warning: sudo() received nonzero return code 1 while executing 'source /etc/contrail/openstackrc; keystone tenant-list'!
2016-03-28 12:17:28:293315:
2016-03-28 12:17:28:293315: 2016-03-28 12:17:28:293171: [root@10.204.217.194] sudo: source /etc/contrail/openstackrc; keystone tenant-list
2016-03-28 12:17:38:300138: [root@10.204.217.194] out: Authorization Failed: An unexpected error prevented the server from fulfilling your request. (HTTP 500)
2016-03-28 12:17:46:685707: [root@10.204.217.194] out:
2016-03-28 12:17:46:701394:

2016-03-28 12:17:46:722329: Warning: sudo() received nonzero return code 1 while executing 'source /etc/contrail/openstackrc; keystone tenant-list'!
2016-03-28 12:17:46:722329:
2016-03-28 12:17:46:722329: 2016-03-28 12:17:46:722180: Traceback (most recent call last):
2016-03-28 12:17:56:731939: File "/usr/local/lib/python2.7/dist-packages/fabric/main.py", line 743, in main
2016-03-28 12:17:56:732043: *args, **kwargs
2016-03-28 12:17:56:754039: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 375, in execute
2016-03-28 12:17:56:754156: multiprocessing
2016-03-28 12:17:56:755008: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 271, in _execute
2016-03-28 12:17:56:755113: return task.run(*args, **kwargs)
2016-03-28 12:17:56:755260: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 171, in run
2016-03-28 12:17:56:755300: return self.wrapped(*args, **kwargs)
2016-03-28 12:17:56:755437: File "/usr/local/lib/python2.7/dist-packages/fabric/decorators.py", line 53, in inner_decorator
2016-03-28 12:17:56:755524: return func(*args, **kwargs)
2016-03-28 12:17:56:761469: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 168, in __call__
2016-03-28 12:17:56:761643: return self.run(*args, **kwargs)
2016-03-28 12:17:56:761760: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 171, in run
2016-03-28 12:17:56:761815: return self.wrapped(*args, **kwargs)
2016-03-28 12:17:56:761910: File "/root/fabric-utils/fabfile/tasks/provision.py", line 2447, in setup_all
2016-03-28 12:17:56:761946: execute('setup_orchestrator')
2016-03-28 12:17:56:767674: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 375, in execute
2016-03-28 12:17:56:767997: multiprocessing
2016-03-28 12:17:56:768211: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 271, in _execute
2016-03-28 12:17:56:768302: return task.run(*args, **kwargs)
2016-03-28 12:17:56:768460: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 171, in run
2016-03-28 12:17:56:768513: return self.wrapped(*args, **kwargs)
2016-03-28 12:17:56:768625: File "/usr/local/lib/python2.7/dist-packages/fabric/decorators.py", line 53, in inner_decorator
2016-03-28 12:17:56:768672: return func(*args, **kwargs)
2016-03-28 12:17:56:768764: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 168, in __call__
2016-03-28 12:17:56:768830: return self.run(*args, **kwargs)
2016-03-28 12:17:56:768939: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 171, in run
2016-03-28 12:17:56:768986: return self.wrapped(*args, **kwargs)
2016-03-28 12:17:56:769120: File "/root/fabric-utils/fabfile/tasks/provision.py", line 2300, in setup_orchestrator
2016-03-28 12:17:56:769172: execute('verify_openstack')
2016-03-28 12:17:56:769700: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 375, in execute
2016-03-28 12:17:56:769756: multiprocessing
2016-03-28 12:17:56:769918: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 271, in _execute
2016-03-28 12:17:56:769966: return task.run(*args, **kwargs)
2016-03-28 12:17:56:770093: File "/usr/local/lib/python2.7/dist-packages/fabric/tasks.py", line 171, in run
2016-03-28 12:17:56:770139: return self.wrapped(*args, **kwargs)
2016-03-28 12:17:56:770249: File "/usr/local/lib/python2.7/dist-packages/fabric/decorators.py", line 53, in inner_decorator
2016-03-28 12:17:56:770295: return func(*args, **kwargs)
2016-03-28 12:17:56:770384: File "/root/fabric-utils/fabfile/tasks/verify.py", line 52, in verify_openstack
2016-03-28 12:17:56:770430: raise OpenStackSetupError(output)
2016-03-28 12:17:56:775172: fabfile.tasks.verify.OpenStackSetupError: Authorization Failed: An unexpected error prevented the server from fulfilling your request. (HTTP 500)
2016-03-28 12:17:56:775395: Disconnecting from 10.204.217.197... done

--------------

In keystone debug log :

2016-03-28 16:31:19.371 16727 DEBUG keystone.middleware.core [-] Auth token not in the request header. Will not build auth context. process_r
equest /usr/lib/python2.7/dist-packages/keystone/middleware/core.py:270
2016-03-28 16:31:19.382 16727 DEBUG keystone.common.wsgi [-] arg_dict: {} __call__ /usr/lib/python2.7/dist-packages/keystone/common/wsgi.py:1
91
2016-03-28 16:31:19.419 16727 DEBUG oslo.db.sqlalchemy.session [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_
DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _init_events /usr/lib/python2.7/dist-pack
ages/oslo/db/sqlalchemy/session.py:461
2016-03-28 16:31:19.454 16727 INFO passlib.registry [-] registered crypt handler 'sha512_crypt': <class 'passlib.handlers.sha2_crypt.sha512_crypt'>
2016-03-28 16:31:19.675 16727 WARNING keystone.openstack.common.versionutils [-] Deprecated: keystone.token.backends.memcache.Token is deprecated as of Juno in favor of keystone.token.persistence.backends.memcache.Token and may be removed in Kilo.
2016-03-28 16:31:19.676 16727 DEBUG keystone.common.kvs.core [-] KVS region configuration for token-driver: {'keystone.kvs.backend': 'openstack.kvs.Memcached', 'keystone.kvs.arguments.distributed_lock': True, 'keystone.kvs.arguments.no_expiry_keys': ['revocation-list'], 'keystone.kvs.arguments.url': ['localhost:11211'], 'keystone.kvs.arguments.memcached_expire_time': 3600, 'keystone.kvs.arguments.memcached_backend': 'memcached', 'keystone.kvs.arguments.lock_timeout': 6} _configure_region /usr/lib/python2.7/dist-packages/keystone/common/kvs/core.py:240
2016-03-28 16:31:19.682 16727 INFO keystone.common.kvs.core [-] Using default dogpile sha1_mangle_key as KVS region token-driver key_mangler
2016-03-28 16:31:27.831 16727 WARNING keystone.common.wsgi [-] Maximum lock attempts on _lockusertokens-2702fe279fd24bc2991219b38d76c45d occurred. (Disable debug mode to suppress these details.)
2016-03-28 16:31:27.834 16727 INFO eventlet.wsgi.server [-] 192.168.192.60 - - [28/Mar/2016 16:31:27] "POST /v2.0/tokens HTTP/1.1" 500 376 8.463476

--------------

[Vedamurthy Joshi (vedujoshi)]

testbed :

host1 = 'root@10.204.217.194'
host2 = 'root@10.204.217.197'
host3 = 'root@10.204.217.198'
host4 = 'root@10.204.217.113'
host5 = 'root@10.204.217.114'
host6 = 'root@10.204.217.115'
host7 = 'root@10.204.217.76'

kvm_node1 = '10.204.217.130'

ext_routers = [('umesh','7.7.7.78')]
router_asn = 64512
public_vn_rtgt = 2223
public_vn_subnet = '10.204.221.176/28'

host_build = 'stack@10.204.216.49'

env.roledefs = {
    'all': [host1, host2, host3, host4, host5, host6, host7],
    'cfgm': [host1, host2, host3],
    'openstack': [host1, host2, host3],
    'webui': [host2],
    'control': [host1, host2, host3],
    'compute': [host4, host5, host6, host7],
    'collector': [host1, host2, host3],
    'database': [host1, host2, host3],
    'build': [host_build],
    'toragent': [host5, host6],
    'tsn': [host5, host6],
}

env.hostnames = {
    'all': ['testbed-1-vm1', 'testbed-1-vm2', 'testbed-1-vm3', 'nodei1', 'nodei2', 'nodei3', 'nodeg36']
}
control_data = {
    host1 : { 'ip': '192.168.192.60/24', 'gw' : '192.168.192.254', 'device':'eth1' },
    host2 : { 'ip': '192.168.192.50/24', 'gw' : '192.168.192.254', 'device':'eth1' },
    host3 : { 'ip': '192.168.192.40/24', 'gw' : '192.168.192.254', 'device':'eth1' },
    host4 : { 'ip': '192.168.192.1/24', 'gw' : '192.168.192.254', 'device':'p6p2' },
    host5 : { 'ip': '192.168.192.2/24', 'gw' : '192.168.192.254', 'device':'p6p2' },
    host6 : { 'ip': '192.168.192.3/24', 'gw' : '192.168.192.254', 'device':'p6p2' },
    host7 : { 'ip': '192.168.192.7/24', 'gw' : '192.168.192.254', 'device':'p1p2' },
}

env.ha = {
    'internal_vip' : '192.168.192.251',
    'contrail_internal_vip' : '192.168.192.251',
}

[Rudra Rugge (rrugge)]

Please reopen if you still see the issue