OpenStack Identity (keystone)

Bug #1405458
Comment #0

Comment 0 for bug 1405458

Revision history for this message

Pavel Gluschak (scsnow) wrote on 2014-12-24:

2014.2.1 on CentOS 7

My LDAP config:

* /etc/keystone/domains/keystone.bluepages.conf
[ldap]
url = ldap://bluepages.ibm.com
query_scope = one
user_tree_dn = c=ru,ou=bluepages,o=ibm.com
user_objectclass = ibmPerson
user_id_attribute = uid
user_name_attribute = mail
user_mail_attribute = mail
user_pass_attribute =
user_enabled_attribute =
#user_enabled_emulation = True
#user_enabled_emulation_dn = cn=openstack,ou=memberlist,ou=ibmgroups,o=ibm.com
user_allow_create = False
user_allow_update = False
user_allow_delete = False

[identity]
driver = keystone.identity.backends.ldap.Identity

I was experimenting with requesting of auth tokens:

* token-req.json
{
    "auth": {
        "identity": {
            "methods": [
                "password"
            ],
            "password": {
                "user": {
                    "domain": {
                        "name": "bluepages"
                    },
                    "name": "<email address hidden>",
                    "password": "passw0rd"
                }
            }
        }
    }
}

$ curl -si -d @token-req.json -H "Content-type: application/json" http://localhost:35357/v3/auth/tokens

This works fine, however I see excessive LDAP requests in keystone.log:

2014-12-23 21:26:48.783 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:48.783 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:48.850 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(<email address hidden>)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:49.234 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.234 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:49.235 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:49.238 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:49.247 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:49.247 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:49.248 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:49.614 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.615 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:49.615 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:49.616 24458 DEBUG keystone.common.ldap.core [-] LDAP bind: who=uid=R87162821,c=ru,ou=bluepages,o=ibm.com simple_bind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:891
2014-12-23 21:26:49.960 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.960 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:49.960 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:49.965 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:50.011 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:50.011 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:50.012 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:50.366 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:50.366 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:50.367 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:50.371 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:50.722 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:50.722 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321

1) Why did it perform 2 search requests before bind? The first one with filterstr=(&(<email address hidden>)(objectClass=ibmPerson)) is sufficient to get dn to bind against.
2) I also don't understand two identical search requests with filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) after bind was successfully performed. So instead of doing search&bind, it does search+search+bind+search+search...
3) If I additionally enable "user_enabled_emulation", LDAP backend performs x2 more search requests, which degrades performance significantly. But seems like it's already addressed in #1299033.

2014.2.1 on CentOS 7

My LDAP config:

[identity]
driver = keystone.identity.backends.ldap.Identity

I was experimenting with requesting of auth tokens:

* token-req.json
{
    "auth": {
        "identity": {
            "methods": [
                "password"
            ],
            "password": {
                "user": {
                    "domain": {
                        "name": "bluepages"
                    },
                    "name": "XXXXX@ru.ibm.com",
                    "password": "passw0rd"
                }
            }
        }
    }
}

$ curl -si -d @token-req.json -H "Content-type: application/json" http://localhost:35357/v3/auth/tokens

This works fine, however I see excessive LDAP requests in keystone.log:

2014-12-23 21:26:48.783 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:48.783 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:48.850 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(mail=XXXXX@ru.ibm.com)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:49.234 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.234 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:49.235 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:49.238 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:49.247 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:49.247 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:49.248 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:49.614 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.615 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:49.615 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:49.616 24458 DEBUG keystone.common.ldap.core [-] LDAP bind: who=uid=R87162821,c=ru,ou=bluepages,o=ibm.com simple_bind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:891
2014-12-23 21:26:49.960 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:49.960 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:49.960 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:49.965 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:50.011 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:50.011 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:50.012 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:50.366 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:50.366 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321
2014-12-23 21:26:50.367 24458 DEBUG keystone.identity.core [-] Local ID: R87162821 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:339
2014-12-23 21:26:50.371 24458 DEBUG keystone.identity.core [-] Found existing mapping to public ID: 8136eec10a5c7f6d61f130e875687f50368c5d8bdfd53454a9647e69b5132991 _set_domain_id_and_mapping_for_single_ref /usr/lib/python2.7/site-packages/keystone/identity/core.py:352
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP init: url=ldap://bluepages.ibm.com _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:571
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP init: use_tls=False tls_cacertfile=None tls_cacertdir=None tls_req_cert=2 tls_avail=1 _common_ldap_initialization /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:575
2014-12-23 21:26:50.375 24458 DEBUG keystone.common.ldap.core [-] LDAP search: base=c=ru,ou=bluepages,o=ibm.com scope=1 filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) attrs=['', 'uid', 'mail'] attrsonly=0 search_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:926
2014-12-23 21:26:50.722 24458 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/site-packages/keystone/common/ldap/core.py:899
2014-12-23 21:26:50.722 24458 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: 9311e7259dc145a4a5acbe829f77cf1b, Default Driver: False, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/site-packages/keystone/identity/core.py:321

1) Why did it perform 2 search requests before bind? The first one with filterstr=(&(mail=XXXXX@ru.ibm.com)(objectClass=ibmPerson)) is sufficient to get dn to bind against.
2) I also don't understand two identical search requests with filterstr=(&(uid=R87162821)(objectClass=ibmPerson)) after bind was successfully performed. So instead of doing search&bind, it does search+search+bind+search+search...
3) If I additionally enable "user_enabled_emulation", LDAP backend performs x2 more search requests, which degrades performance significantly. But seems like it's already addressed in #1299033.