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
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
Hi Eric,
Is there a command to gather all the logs centrally?
Myles
ericwbrown Any joy?
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
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.