OpenStack Identity (keystone)

excessive ldap requests

Bug #1405458 reported by Pavel Gluschak on 2014-12-24

This bug affects 5 people

Affects		Status	Importance	Assigned to	Milestone
	OpenStack Identity (keystone)	Triaged	Low	Unassigned

Bug Description

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...

See original description

Tags:

Revision history for this message

Morgan Fainberg (mdrnstm) wrote on 2015-01-13:

This is a relatively known issue. We are aware that our LDAP driver is very chatty and that it can be a bottle neck.

Changed in keystone:
status:	New → Triaged
importance:	Undecided → Medium

Grzegorz Grasza (xek) on 2015-11-19

Changed in keystone:
assignee:	nobody → Grzegorz Grasza (xek)

Revision history for this message

Steve Martinelli (stevemar) wrote on 2015-11-30:

updating the description to remove #3 (enabled emulation slows ldap down) as it's covered in https://bugs.launchpad.net/keystone/+bug/1299033

description:

updated

Alicja Kwasniewska (alicja-kwasniewska) on 2016-01-07

Changed in keystone:
assignee:	Grzegorz Grasza (xek) → Alicja Kwasniewska (alicja-kwasniewska)

Grzegorz Grasza (xek) on 2016-02-11

Changed in keystone:
assignee:	Alicja Kwasniewska (alicja-kwasniewska) → nobody

Revision history for this message

Morgan Fainberg (mdrnstm) wrote on 2016-03-02:

This fix: https://review.openstack.org/#/c/272007/ should help move us in the right direction

Revision history for this message

Morgan Fainberg (mdrnstm) wrote on 2016-03-02:

lowering priority since new code is being developed for py3 compat against the ldap3 library instead of retrofitting the current code to use ldap3. tagged as "ldap-legacy" so it can be closed when/if the current driver is deprecated in favor of the new py3 compatible code

tags:	added: ldap-legacy
Changed in keystone:
importance:	Medium → Low

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.