Two succesive LDAP-Queries (one fail; one success) with two different Password-Parameter

aexlz · August 9, 2018, 12:35pm

Dear privacyIDEA-Team,

after implementing privacyIDEA via Ubuntu-Packages (16.04) and migrating Token, Resolver and Realms via the Migration Script from LinOTP, everything works fine (SO FAR). The clients, which had a TOTP in LinOTP, can succesfully validate their token with the URL-Check. Anyhow: By viewing the log (INFO and DEBUG) I am wondering, why LDAP-Queries for certain user happen twice. One with wrong Credentials(AD-PW+OTP) and the next time after with correct credentials (AD-PW).
To be more precise:
User1: di12345; Realm=dh; Resolver: dhcom --> One LDAP Query with success
User2: a123456; Realm=dh; Resolver: dhcom --> Two LDAP Queries, last with success

I added a few log.debugs in the lib/resolvers/LDAPResolver (privacyidea.log):
Wrong Credential:

[2018-08-09 14:02:56,771][1205][140655766451968][DEBUG][privacyidea.lib.resolver:197] Exiting get_resolver_object with result <privacyidea.lib.resolvers.LDAPIdResolver.IdResolver object at 0x7fecc567afd0>
[2018-08-09 14:02:56,776][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:791] Added ldapserverONE, None, False to server pool.
[2018-08-09 14:02:56,776][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:282] Authtype: u’Simple’
[2018-08-09 14:02:56,776][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:283] user : u’CN=a440216,CN=Users,DC=dh-com,DC=continental,DC=steel’
[2018-08-09 14:02:56,782][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:298] self.authtype: u’Simple’
[2018-08-09 14:02:56,782][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:299] server_pool: ServerPool(servers=[Server(host=u’ldapserverONE’, port=389, use_ssl=False, allowed_referral_hosts=[(’*’, True)]$
[2018-08-09 14:02:56,782][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:300] password: u’AD-PW047805’
[2018-08-09 14:02:56,782][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:301] self.timeout: 20.0
[2018-08-09 14:02:56,783][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:302] not self.noreferrals: False
[2018-08-09 14:02:56,783][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:303] self.start_tls: False
[2018-08-09 14:02:56,783][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:304] bind result: False
[2018-08-09 14:02:56,783][1205][140655766451968][WARNING][privacyidea.lib.resolvers.LDAPIdResolver:311] failed to check password for u’a440216’/u’CN=a440216,CN=Users,DC=dh-com,DC=continental,DC=steel’: Exception(‘Wrong credentials’,)
[2018-08-09 14:02:56,783][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:312] Traceback (most recent call last):
File “/usr/lib/python2.7/dist-packages/privacyidea/lib/resolvers/LDAPIdResolver.py”, line 306, in checkPass
raise Exception(“Wrong credentials”)
Exception: Wrong credentials

Success:

[2018-08-09 14:02:56,790][1205][140655766451968][DEBUG][privacyidea.lib.resolver:197] Exiting get_resolver_object with result <privacyidea.lib.resolvers.LDAPIdResolver.IdResolver object at 0x7fecc567afd0>
[2018-08-09 14:02:56,791][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:205] Reading u’a440216’ from cache for ‘_getDN’
[2018-08-09 14:02:56,792][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:791] Added ldapserverONE, None, False to server pool.
[2018-08-09 14:02:56,792][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:282] Authtype: u’Simple’
[2018-08-09 14:02:56,792][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:283] user : u’CN=a440216,CN=Users,DC=dh-com,DC=continental,DC=steel’
[2018-08-09 14:02:56,797][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:298] self.authtype: u’Simple’
[2018-08-09 14:02:56,797][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:299] server_pool: ServerPool(servers=[Server(host=u’ldapserverONE’, port=389, use_ssl=False, allowed_referral_hosts=[(’*’, True)]$
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:300] password: u’AD-PW’
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:301] self.timeout: 20.0
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:302] not self.noreferrals: False
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:303] self.start_tls: False
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:304] bind result: True
[2018-08-09 14:02:56,798][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:307] bind seems successful.
[2018-08-09 14:02:56,799][1205][140655766451968][DEBUG][privacyidea.lib.resolvers.LDAPIdResolver:309] unbind successful.
[2018-08-09 14:02:56,800][1205][140655766451968][DEBUG][privacyidea.lib.user:357] Successfully authenticated user User(login=u’a440216’, realm=u’dh’, resolver=u’dh-comad’).
[2018-08-09 14:02:56,800][1205][140655766451968][DEBUG][privacyidea.lib.user:197] Exiting check_password with result a440216@dh

Please let me know, if you need more information!
Thanks in advance.
Best wishes
Axel

cornelinux · August 9, 2018, 5:13pm

Welcome to privacyIDEA, former LinOTP user!

Success Case

This is actually done in the check_password method (which you can see at the end of the log.
This is the way it should be. The entered password is split into PIN and OTP and only the PIN (static part) is sent to the userstore.

Fail Case

You see that the complete part including OTP is sent to LDAP.
So I assume you have some authentication policies, that actually send the complete PW to the userstore.
Thus it would work as intended.

Please take a look at your policies or send them here.

Kind regards
Cornelius

aexlz · August 9, 2018, 5:33pm

Hello,
many thanks for your fast reply!
Fail Case:
I have got an authentication-policy otppin=userstore, which affects both user (aUserOne, diUserTwo), because both of them share the same realm&useridresolver.
That is, what surprises me. I expected privacyIDEA to authenticate both user the exact same way …but aUserOne got authenticated “twice” against the LDAP although it shares the same policy with diUserTwo.

Kind regards
Axel

cornelinux · August 9, 2018, 6:05pm

Check, if you have further policies.

Also in the fail case, you need to take a look not only at the LDAP Resolver debug messages but also at the preceeding messages. (I.e. the call stack - how comes it that the OTP is sent to LDAP?)
This way you will learn why the ldap resolver was entered with the PIN+OTP.

Kind regards
Cornelius

fredreichbier · August 9, 2018, 6:35pm

Hi Axel,

this is an interesting problem. Just a thought: Could it be the case that a123456 has a SPASS token enrolled in addition to the TOTP token? In combination with a otppin=userstore policy, this could lead to two BIND requests to the LDAP server.

Best Regards

Friedrich

aexlz · August 9, 2018, 7:21pm

Hello Friedrich,
thanks for your reply. a123456 has only got an additional SMS Token. Could that also cause the two ldap-binds? After migrating from LinOTP, I created only one policy, which i mentioned before(otppin=userstore), affecting all realms and all useridresolver.
Right after the Exception “Wrong credentials” in checkPass the call stack repeats itself with the difference, that on the one hand: a44016 get fetched from the cache ( u’a440216’ from cache for ‘_getDN’) and the log.debug("…".format(password) contains the the user-store pw only. When and where does the password-string got split (had big problems finding this certain method)? May be this makes it easier to find out, why he ran through this workflow for the second ldap-bind.
Cornelius is right with his suggestion looking for the complete call stack, but one policy for two user of the same realm&useridresolver should affect their “authentication-ldap-binds” same.

Kind regards
Axel

aexlz · August 9, 2018, 7:28pm

I am sorry…just rethinking the whole thing leads to a solution, I guess. A second token must be the solution for this self-made “problem”! Validating via /validate/check leads privacyidea (and that is the one and only correct way) to validate the incoming request against the ldap twice! One time for each token…The first time must have been the SMS-Token, which in fact caused a “Wrong credential”. The second time was the correct token (TOTP) with the correct credentials…Let me know if I am totally wrong…
Sorry for not having an eye on the obvious things. Many thanks for your help and I am looking forward to meet up again in the near future…

Kind regards
Axel Czuck

cornelinux · August 9, 2018, 9:26pm

The SMS token will verify the complete entered password-value as “OTP PIN”, since this would trigger the sending of the SMS.

So yes. The SMS token causes AD-PW047805 to be sent to LDAP, it does not match the ldap password, the SMS is not send. Now privacyIDEA checks the next token, the TOTP token. This requires the AD-PW047805 to be split. Only “AD-PW” is sent to the LDAP - success. Bang. Found the right token - now the OTP is validated.

If you want to get into more detail, you may read here:
http://privacyidea.readthedocs.io/en/latest/modules/api/validate.html

The acutal magic happens in check_token_list:
http://privacyidea.readthedocs.io/en/latest/modules/lib/tokenfunction.html#privacyidea.lib.token.check_token_list

http://privacyidea.readthedocs.io/en/latest/_modules/privacyidea/lib/token.html#check_token_list

This will iterate through all tokens of the user and fill lists of

Tokens matching the PIN
tokens matching PIN and OTP
tokens mathing the PIN and triggering a challenge (potentielly the SMS)
tokens that answered a challenge
tokens that do absolutely not fit…

And to determine no. 3, the first failed LDAP request was issued.

Kind regards
Cornelius

aexlz · August 9, 2018, 10:09pm

That definetely clarified my confusion.
Thank you very much.

Kind regards

Axel