Activity log for bug #1405458

Date Who What changed Old value New value Message
2014-12-24 17:36:36 Pavel Gluschak bug added bug
2015-01-13 17:04:32 Morgan Fainberg keystone: status New Triaged
2015-01-13 17:04:34 Morgan Fainberg keystone: importance Undecided Medium
2015-11-19 14:48:00 Grzegorz Grasza keystone: assignee Grzegorz Grasza (xek)
2015-11-30 02:15:49 Steve Martinelli 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": "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. 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": "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...
2016-01-07 08:54:58 Alicja Kwasniewska keystone: assignee Grzegorz Grasza (xek) Alicja Kwasniewska (alicja-kwasniewska)
2016-01-28 22:09:38 Thomas Hsiao bug added subscriber Thomas Hsiao
2016-02-07 08:28:16 Tin Lam bug added subscriber Tin Lam
2016-02-11 14:55:53 Grzegorz Grasza keystone: assignee Alicja Kwasniewska (alicja-kwasniewska)
2016-03-02 21:44:08 Morgan Fainberg tags ldap ldap ldap-legacy
2016-03-02 21:44:56 Morgan Fainberg keystone: importance Medium Low
2016-10-17 20:52:47 Thomas Hsiao removed subscriber Thomas Hsiao