[Freeipa-users] 'Preauthentication failed' with SSSD in ipa_server_mode

Mon Mar 23 15:37:34 UTC 2015

>On 03/20/2015 08:05 AM, Alexander Bokovoy wrote:
>> On Fri, 20 Mar 2015, Bobby Prins wrote:
>>>> On Fri, 20 Mar 2015, Sumit Bose wrote:
>>>>> On Fri, Mar 20, 2015 at 11:44:43AM +0100, Bobby Prins wrote:
>>>>>> On Thu, Mar 19, 2015 at 04:46:44PM +0100, Bobby Prins wrote:
>>>>>> >> Hi there,
>>>>>> >>
>>>>>> >> I'm currently trying to use the 'AD Trust for Legacy Clients'
>>>>>> >> freeIPA setup (described here:
>>>>>> >> http://www.freeipa.org/images/0/0d/FreeIPA33-legacy-clients.pdf)
>>>>>> >> to be able to autenticate AIX 7.1 clients against an AD domain
>>>>>> >> using LDAP. After the trust was created all seems to work well
>>>>>> >> on the freeIPA server. I can also do a lookup of AD users and
>>>>>> >> groups on an AIX test server.
>>>>>> >>
>>>>>> >> But as soon as I want to log in on the AIX system I get an SSSD 
>>>>>> error on the freeIPA server in krb5_child.log (debug_level = 10):
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590260: AS 
>>>>>> key obtained for encrypted timestamp: aes256-cts/2F5D
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590326: 
>>>>>> Encrypted timestamp (for 1426778442.525165): plain 
>>>>>> 301AA011180F32303135303331393135323034325AA105020308036D, 
>>>>>> encrypted 
>>>>>> 9B3299264F09E50D63D84B385A09A4C64D44116A02B58FFF12830B39F88722CD9B792F5ABA0653578DE9138B91D29C17C197453D8B8A5E7A
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590349: 
>>>>>> Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590360: 
>>>>>> Produced preauth for next request: 2
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.590384: 
>>>>>> Sending request (238 bytes) to EXAMPLE.CORP
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591325: 
>>>>>> Resolving hostname dct020.example.corp.
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.591889: 
>>>>>> Sending initial UDP request to dgram 192.168.143.1:88
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636127: 
>>>>>> Received answer from dgram 192.168.143.1:88
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636626: 
>>>>>> Response was not from master KDC
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636667: 
>>>>>> Received error from KDC: -1765328360/Preauthentication failed
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636698: 
>>>>>> Preauth tryagain input types: 16, 14, 19, 2
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636728: 
>>>>>> Retrying AS request with master KDC
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636741: 
>>>>>> Getting initial credentials for BPrins at EXAMPLE.CORP
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [sss_child_krb5_trace_cb] (0x4000): [12775] 1426778442.636787: 
>>>>>> Sending request (160 bytes) to EXAMPLE.CORP (master)
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [get_and_save_tgt] (0x0020): 979: [-1765328360][Preauthentication 
>>>>>> failed]
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [map_krb5_error] (0x0020): 1040: [-1765328360][Preauthentication 
>>>>>> failed]
>>>>>> >> (Thu Mar 19 16:20:42 2015) [[sssd[krb5_child[12775]]]] 
>>>>>> [k5c_send_data] (0x0200): Received error code 1432158214
>>>>>> >>
>>>>>> >> If I do the same with 'KRB5_TRACE=/dev/stderr kinit 
>>>>>> BPrins at EXAMPLE.CORP':
>>>>>> >> [12299] 1426773524.361785: AS key obtained for encrypted 
>>>>>> timestamp: aes256-cts/B997
>>>>>> >> [12299] 1426773524.361850: Encrypted timestamp (for 
>>>>>> 1426773524.277583): plain 
>>>>>> 301AA011180F32303135303331393133353834345AA1050203043C4F, 
>>>>>> encrypted 
>>>>>> ED9CF995617740C4B14DB9CC84187E3505B664FE5C0AD16D19477E912F5400FB2C4665A090E3A37CD749535B3C80595809E14D15CB3527C0
>>>>>> >> [12299] 1426773524.361876: Preauth module encrypted_timestamp 
>>>>>> (2) (flags=1) returned: 0/Success
>>>>>> >> [12299] 1426773524.361880: Produced preauth for next request: 2
>>>>>> >> [12299] 1426773524.361901: Sending request (238 bytes) to 
>>>>>> EXAMPLE.CORP
>>>>>> >> [12299] 1426773524.363002: Resolving hostname dct020.EXAMPLE.corp.
>>>>>> >> [12299] 1426773524.363841: Sending initial UDP request to dgram 
>>>>>> 192.168.141.1:88
>>>>>> >> [12299] 1426773524.368089: Received answer from dgram 
>>>>>> 192.168.141.1:88
>>>>>> >> [12299] 1426773524.368482: Response was not from master KDC
>>>>>> >> [12299] 1426773524.368500: Received error from KDC: 
>>>>>> -1765328332/Response too big for UDP, retry with TCP
>>>>>> >> [12299] 1426773524.368506: Request or response is too big for 
>>>>>> UDP; retrying with TCP
>>>>>> >> [12299] 1426773524.368511: Sending request (238 bytes) to 
>>>>>> EXAMPLE.CORP (tcp only)
>>>>>> >> [12299] 1426773524.368953: Resolving hostname dct030.EXAMPLE.corp.
>>>>>> >> [12299] 1426773524.370056: Initiating TCP connection to stream 
>>>>>> 192.168.143.5:88
>>>>>> >> [12299] 1426773524.375140: Sending TCP request to stream 
>>>>>> 192.168.143.5:88
>>>>>> >> [12299] 1426773524.383801: Received answer from stream 
>>>>>> 192.168.143.5:88
>>>>>> >> [12299] 1426773524.384237: Response was not from master KDC
>>>>>> >> [12299] 1426773524.384263: Processing preauth types: 19
>>>>>> >> [12299] 1426773524.384271: Selected etype info: etype 
>>>>>> aes256-cts, salt "EXAMPLE.CORPBPrins", params ""
>>>>>> >> [12299] 1426773524.384275: Produced preauth for next request: 
>>>>>> (empty)
>>>>>> >> [12299] 1426773524.384282: AS key determined by preauth: 
>>>>>> aes256-cts/B997
>>>>>> >> [12299] 1426773524.384329: Decrypted AS reply; session key is: 
>>>>>> rc4-hmac/39AB
>>>>>> >> [12299] 1426773524.384333: FAST negotiation: unavailable
>>>>>> >> [12299] 1426773524.384357: Initializing 
>>>>>> KEYRING:persistent:0:krb_ccache_rhX3V4v with default princ 
>>>>>> BPrins at EXAMPLE.CORP
>>>>>> >> [12299] 1426773524.384400: Removing BPrins at EXAMPLE.CORP -> 
>>>>>> krbtgt/EXAMPLE.CORP at EXAMPLE.CORP from 
>>>>>> KEYRING:persistent:0:krb_ccache_rhX3V4v
>>>>>> >> [12299] 1426773524.384407: Storing BPrins at EXAMPLE.CORP -> 
>>>>>> krbtgt/EXAMPLE.CORP at EXAMPLE.CORP in 
>>>>>> KEYRING:persistent:0:krb_ccache_rhX3V4v
>>>>>> >> [12299] 1426773524.384469: Storing config in 
>>>>>> KEYRING:persistent:0:krb_ccache_rhX3V4v for 
>>>>>> krbtgt/EXAMPLE.CORP at EXAMPLE.CORP: pa_type: 2
>>>>>> >> [12299] 1426773524.384484: Removing BPrins at EXAMPLE.CORP -> 
>>>>>> krb5_ccache_conf_data/pa_type/krbtgt\/EXAMPLE.CORP\@EXAMPLE.CORP at X-CACHECONF: 
>>>>>> from KEYRING:persistent:0:krb_ccache_rhX3V4v
>>>>>> >> [12299] 1426773524.384492: Storing BPrins at EXAMPLE.CORP -> 
>>>>>> krb5_ccache_conf_data/pa_type/krbtgt\/EXAMPLE.CORP\@EXAMPLE.CORP at X-CACHECONF: 
>>>>>> in KEYRING:persistent:0:krb_ccache_rhX3V4v
>>>>>> >>
>>>>>> >> Any ideas?
>>>>>> >
>>>>>> >Can you log in to the IPA server as this user? If yes I would assume
>>>>>> >that the password gets garbled somewhere on the way from AIX 
>>>>>> through the
>>>>>> >IPA machinery to SSSD. Does the password contain some special 
>>>>>> characters
>>>>>> >which some LDAP processing calls might want the escape?
>>>>>> >
>>>>>> >bye,
>>>>>> >Sumit
>>>>>> >
>>>>>> Yes, I can login with the account on the IPA server without any
>>>>>> problems. I tried it with different password to rule out problems
>>>>>> with special characters. Finally I did a tcpdump on the IPA server.
>>>>>> The AIX server sends the word 'INCORRECT' to the IPA server instead
>>>>>> of the password. So I guess I have to do some more configuration
>>>>>> checks on the AIX server.
>>>>>
>>>>> Thank you for the feedback.
>>>>>
>>>>> Just a wild guess, since you were able to see anything in the 
>>>>> tcpdump I
>>>>> guess an unencrypted connection is used. Maybe AIX prevents that the
>>>>> password is send via a clear text connection?
>>>> It is openssh behavior. It sends INCORRECT line as part of the password
>>>> when there is no valid shell for that user to login.
>>>>
>>>> OpenSSH validates content of 'struct passwd' returned for the user,
>>>> including checks on whether shell is there as an executable file. This
>>>> check fails and user is considered 'invalid'. Still, OpenSSH competes
>>>> PAM authentication, making sure the password field is filled with
>>>> specially constructed string "\b\n\r\177INCORRECT", to ensure there is
>>>> registered failed login attempt.
>>> Wow, thanks for that! If I do a lsuser/ldapsearch on the AIX host the
>>> shell/loginShell is missing for AD users. The admin IPA user has this
>>> attribute set and I can log in with that account. Can this be solved on
>>> the IPA server?
>> In FreeIPA 4.1 (Fedora 21+ or RHEL7.1) you can do set shell separately
>> for each AD user using ID Views:
>>
>> ipa idoverrideuser-add 'Default Trust View' 'AD\User' --shell /bin/ksh
>>
>> Compat tree and SSSD on RHEL7.1/Fedora21 should take default trust view
>> into account for AD users.
>>
>Once we are out of the woods here it would be really nice to have a blog 
>or a wiki page about how to configure AIX clients properly to leverage 
>trusts including this interesting aspect related to the shell.
>Bobby would you be able to share this information?
>
>-- 
>Thank you,
>Dmitri Pal

No problem Dmitri. Would love to help with that!

At the moment I'm still getting 'invalid user' messages on the AIX side even though the shell is set using an ID view.

SSH server logging:
debug3: AIX/loginrestrictions returned -1 msg 3004-300 You entered an invalid login name or password.
Login restricted for bprins at aero.corp: 3004-300 You entered an invalid login name or password.

Console logging:
AIX Version 7
Copyright IBM Corporation, 1982, 2013.
Console login: bprins at example.corp
bprins at example.corp's Password:
3004-300 You entered an invalid login name or password.

'max_logname' in AIX is set to '50' (default is 9(?)). The only account attribute differences with a valid AIX user are the rather high id/UID and the pgrp/primary group and user name which contain a . and @-sign for the AD user. A local user on the AIX server with a high UID and symbols in the username can login (did some testing with different user names).

For now, SSSD seems to handle the authentication request against AD without any problems if I try a console login.