VMware Cloud Community
Mutant_Tractor
Enthusiast
Enthusiast
‎04-18-2016 12:26 PM

Deploying VIO 2.0.3 with AD fails repeatedly

Hi All,

Trying to deploy VIO with the latest 2.0.3 OVA fails when using AD integration of any kind (SSL or no encryption).

Deploys fine without AD - I'm using NSX for networking.

Binding user is passed in as: _openstackad@lab.mylesgray.io

All tests pass in the AD wizard during deploy.

Seen in the management appliance jarvis.log:

2016-04-18 18:56:48,918 p=316 u=jarvis |  TASK: [config-controller | grant service role to service user on service tenant] ***

2016-04-18 18:56:49,794 p=316 u=jarvis |  failed: [10.0.3.157] => {"failed": true}

2016-04-18 18:56:49,794 p=316 u=jarvis |  msg: exception: name

2016-04-18 18:56:49,794 p=316 u=jarvis |  FATAL: all hosts have already failed -- aborting

On the controller node 10.0.3.157 in keystone.log nothing seems untoward - can see it pulling back users from AD:

2016-04-18 18:56:49.691 15825 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://lab.mylesgray.io:389 _common_ldap_initialization /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:576

2016-04-18 18:56:49.692 15825 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=/etc/keystone/ssl/certs/ tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:580

2016-04-18 18:56:49.729 15825 DEBUG keystone.common.ldap.core [-] LDAP bind: who=_openstackad@lab.mylesgray.io simple_bind_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:896

2016-04-18 18:56:49.733 15825 DEBUG keystone.common.ldap.core [-] LDAP search: base=OU=Users,OU=Lab,DC=lab,DC=mylesgray,DC=io scope=2 filterstr=(&(objectClass=organizationalPerson)) attrs=['cn', 'userPassword', 'userAccountControl', 'userPrincipalName', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:931

2016-04-18 18:56:49.734 15825 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:904

2016-04-18 18:56:49.735 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.735 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.736 15825 DEBUG keystone.identity.core [-] Local ID: Myles Gray _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.736 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.736 15825 DEBUG keystone.identity.core [-] Local ID: Ryan Gray _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.736 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.737 15825 DEBUG keystone.identity.core [-] Local ID: krbtgt _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.737 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.737 15825 DEBUG keystone.identity.core [-] Local ID: Administrator _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.737 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.738 15825 DEBUG keystone.identity.core [-] Local ID: NDES Service User _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.738 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.738 15825 DEBUG keystone.identity.core [-] Local ID: Eaton IPM _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.739 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.739 15825 DEBUG keystone.identity.core [-] Local ID: PuttyCat Service _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.739 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.740 15825 DEBUG keystone.identity.core [-] Local ID: vRealize Service User _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.740 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.740 15825 DEBUG keystone.identity.core [-] Local ID: Veeam Backup _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.741 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.741 15825 DEBUG keystone.identity.core [-] Local ID: Dell OpenManage Essentials _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.741 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.742 15825 DEBUG keystone.identity.core [-] Local ID: Cloud Physics Service _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.742 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.742 15825 DEBUG keystone.identity.core [-] Local ID: Git Lab _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.743 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.743 15825 DEBUG keystone.identity.core [-] Local ID: Guest _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.743 15825 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492

2016-04-18 18:56:49.743 15825 DEBUG keystone.identity.core [-] Local ID: Openstack AD Binding _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/dist-packages/keystone/identity/core.py:510

2016-04-18 18:56:49.744 15825 INFO eventlet.wsgi.server [-] 127.0.0.1 - - [18/Apr/2016 18:56:49] "GET /v2.0/users HTTP/1.1" 200 1792 0.054815

In heat-engine.log on the same host this can be seen repeating:

2016-04-18 18:41:52.053 14551 ERROR oslo_messaging._drivers.impl_rabbit [-] AMQP server on 127.0.0.1:5672 is unreachable: [Errno 111] ECONNREFUSED. Trying again in 1 seconds.

In nova-conductor.log this can be seen repeating:

2016-04-18 18:40:11.366 7843 ERROR oslo_messaging._drivers.impl_rabbit [req-b237f73e-63f7-46e5-8f21-4d42ae35b39b - - - - -] AMQP server on 127.0.0.1:5672 is unreachable: [Errno 111] ECONNREFUSED. Trying again in 2 seconds.

This is as far as I have managed to come with the posts on the forum, any advice, are there any known bugs with the AD integration portion?

Myles

Reply
0 Kudos
6 Replies
ericwbrown
VMware Employee
VMware Employee
‎04-21-2016 10:42 AM

Be sure to check both controller's keystone logs. The error might be on the other. Also, if you could attach the logs here, we might be able to better debug the issue.  Thanks

Reply
0 Kudos
Mutant_Tractor
Enthusiast
Enthusiast
‎04-22-2016 03:23 AM

Hi Eric,

Is there a command to gather all the logs centrally?

Myles

Reply
0 Kudos
Mutant_Tractor
Enthusiast
Enthusiast
‎04-22-2016 03:37 AM

Logs attached ericwbrown‌

201604221025.tgz
Reply
0 Kudos
Mutant_Tractor
Enthusiast
Enthusiast
‎04-27-2016 01:09 AM

ericwbrown‌ Any joy?

Reply
0 Kudos
rpellet
VMware Employee
VMware Employee
‎05-02-2016 12:31 PM

In the jarvis.log, ansible.log and keystone.log.1 on controller01 we see similar messages at this same timeframe as below.   The LDAP server isn't responding properly.

2016-04-19 20:01:09.297 15944 INFO eventlet.wsgi.server [-] 127.0.0.1 - - [19/Apr/2016 20:01:09] "POST /v2.0/tenants HTTP/1.1" 200 300 0.013276

2016-04-19 20:01:10.142 15948 DEBUG keystone.middleware.core [-] RBAC: auth_context: {} process_request /usr/lib/python2.7/dist-packages/keystone/middleware/core.py:239

2016-04-19 20:01:10.157 15948 INFO keystone.common.wsgi [-] GET /users?

2016-04-19 20:01:10.157 15948 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldaps://lab.mylesgray.io:636 _common_ldap_initialization /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:576

2016-04-19 20:01:10.158 15948 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=/etc/keystone/ssl/certs/ tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:580

2016-04-19 20:01:10.186 15948 DEBUG keystone.common.ldap.core [-] LDAP bind: who=_openstackad@lab.mylesgray.io simple_bind_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:896

2016-04-19 20:01:10.706 15948 ERROR keystone.common.wsgi [-] {'info': 'A TLS packet with unexpected length was received.', 'desc': "Can't contact LDAP server"}   <<<<<<<<<<<<<ERROR

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi Traceback (most recent call last):

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/wsgi.py", line 239, in __call__

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     result = method(context, **params)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/controllers.py", line 50, in get_users

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     CONF.identity.default_domain_id)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/manager.py", line 47, in wrapper

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return f(self, *args, **kwargs)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/core.py", line 342, in wrapper

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return f(self, *args, **kwargs)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/core.py", line 353, in wrapper

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return f(self, *args, **kwargs)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/core.py", line 791, in list_users

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     ref_list = driver.list_users(hints)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/backends/ldap.py", line 82, in list_users

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return self.user.get_all_filtered(hints)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/identity/backends/ldap.py", line 269, in get_all_filtered

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return [self.filter_attributes(user) for user in self.get_all(query)]

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 1874, in get_all

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return super(EnabledEmuMixIn, self).get_all(ldap_filter)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 1505, in get_all

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     for x in self._ldap_get_all(ldap_filter)]

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 1459, in _ldap_get_all

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     with self.get_connection() as conn:

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 1283, in get_connection

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     conn.simple_bind_s(user, password)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 901, in simple_bind_s

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     clientctrls=clientctrls)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py", line 753, in simple_bind_s

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     with self._get_pool_connection() as conn:

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/contextlib.py", line 17, in __enter__

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     return self.gen.next()

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/ldappool/__init__.py", line 291, in connection

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     conn = self._get_connection(bind, passwd)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/ldappool/__init__.py", line 244, in _get_connection

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     conn = self._create_connector(bind, passwd)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi   File "/usr/lib/python2.7/dist-packages/ldappool/__init__.py", line 224, in _create_connector

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi     raise BackendError(str(exc), backend=conn)

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi BackendError: {'info': 'A TLS packet with unexpected length was received.', 'desc': "Can't contact LDAP server"}     <<<<<<<<<<<<<<<ERROR

2016-04-19 20:01:10.706 15948 TRACE keystone.common.wsgi

Reply
0 Kudos
Mutant_Tractor
Enthusiast
Enthusiast
‎05-03-2016 11:38 AM

This appears to have been to do with TLS1.2 being enabled on 2012 R2 and GnuTLS not being compatible:

How to enable TLS 1.2 on Windows Server 2012 R2 for LDAPS clients.

http://ubuntuforums.org/showthread.php?t=2292281

Re: Windows Server 2012 R2 - TLS 1.2 connection errors

The current workaround is to disable TLS1.1 and TLS1.2 on the DCs.

Ended up deploying with no encryption and some other tweaks, writing a blog about it at the moment.

Reply
0 Kudos