kinit on IPA server does not exclusively talk to local KDC

[Lukas Slebodnik]

ehlo,

I realized that it might be better to discuss it here rather then in
pull requests because it seems to be related to two different commits.

I will describe a test case on master with already created replica on another
host.
* kinit as admin
    // create user with dummy password
* echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
                               --password

// adding sleep think that first kinit hits slave sometimes and the user is
    // not replicated yet.
* sleep 2
* FirstKinitAs $login $dummypw $password

FirstKinitAs is a bash function which change initial password
something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username

Such test works reliably with 1.15.3 and kinit always talk to local master
(I didn't try to remove sleep 2)

But situation changed a little bit with git master due to following commits
IPA: Only generate kdcinfo files on clients
https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
localauth plugin: change return code of sss_an2ln
https://pagure.io/SSSD/sssd/c/3f94a979eebd1c9496b49b4e07b7823550dec97e

It is enough to revert just one of these patches and situation is back stable

BTW failure is not 100% reliable but it happens quite often 40-60% of cases.
And I think kinit on IPA server should always talk to local KDC unless
it is down.

Attaching two logs with KRB5TRACE + SSSD_KRB5_LOCATOR_DEBUG

LS

[Sumit Bose]

On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> ehlo,
>
> I realized that it might be better to discuss it here rather then in
> pull requests because it seems to be related to two different commits.
>
> I will describe a test case on master with already created replica on another
> host.
>
> kinit as admin
>   // create user with dummy password
>
> echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
>                              --password
>
> // adding sleep think that first kinit hits slave sometimes and the user is
>   // not replicated yet.
>
> sleep 2
>
> FirstKinitAs $login $dummypw $password
>
> FirstKinitAs is a bash function which change initial password
> something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
>
> Such test works reliably with 1.15.3 and kinit always talk to local master
> (I didn't try to remove sleep 2)
>
> But situation changed a little bit with git master due to following commits
> IPA: Only generate kdcinfo files on clients
> https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6

Do you have the /etc/krb5.conf available from the host where the test
failed. The above patch was written with the assumption that
/etc/krb5.conf on the IPA server points to the server itself as
ipa-server-install creates it:

[realms]
 IPA.DEVEL = {
  kdc = ipa-devel.ipa.devel:88
  master_kdc = ipa-devel.ipa.devel:88
  admin_server = ipa-devel.ipa.devel:749
  default_domain = ipa.devel
  pkinit_anchors = FILE:/etc/ipa/ca.crt
}

Currently I would assume that at least admin_server is missing.
> localauth plugin: change return code of sss_an2ln
> https://pagure.io/SSSD/sssd/c/3f94a979eebd1c9496b49b4e07b7823550dec97e

I'm a bit surprised here because it is not clear to me where during the
test an2ln is used. But if it is the case it might point to an issue at
a different place because the old return code was wrong according to the
documentation of the plugin.

bye,
Sumit
> It is enough to revert just one of these patches and situation is back stable
>
> BTW failure is not 100% reliable but it happens quite often 40-60% of cases.
> And I think kinit on IPA server should always talk to local KDC unless
> it is down.
>
> Attaching two logs with KRB5TRACE + SSSD_KRB5_LOCATOR_DEBUG
>
> LS
> Added user "selfservuser1"
>
> User login: selfservuser1
>   First name: first
>   Last name: last
>   Full name: first last
>   Display name: first last
>   Initials: fl
>   Home directory: /home/selfservuser1
>   GECOS: first last
>   Login shell: /bin/sh
>   Principal name: [e-mail]
>   Principal alias: [e-mail]
>   Email address: [e-mail]
>   UID: 1739200021
>   GID: 1739200021
>   Password: True
>   Member of groups: ipausers
>   Kerberos keys available: True
> :: [   PASS   ] :: add test user account (Expected 0, got 0)
> :: [  BEGIN   ] :: Running 'FirstKinitAs selfservuser1 [e-mail] passw0rd1'
> [2008] 1504979429.356684: Destroying ccache KEYRING:persistent:0:0
> Using default cache: persistent:0:0
> Using principal: [e-mail]
> [2010] 1504979429.362816: Getting initial credentials for [e-mail]
> [2010] 1504979429.364886: Sending request (183 bytes) to TESTRELM.TEST
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[1]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[1]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.365050: Initiating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.365114: Sending TCP request to stream 10.19.41.54:88
> [2010] 1504979429.366775: Received answer (186 bytes) from stream 10.19.41.54:88
> [2010] 1504979429.366783: Terminating TCP connection to stream 10.19.41.54:88
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.366833: Response was from master KDC
> [2010] 1504979429.366849: Received error from KDC: -1765328361/Password has expired
> [2010] 1504979429.366866: Principal expired; getting changepw ticket
> [2010] 1504979429.366871: Getting initial credentials for [e-mail]
> [2010] 1504979429.366885: Setting initial creds service to kadmin/changepw
> [2010] 1504979429.366901: Sending request (178 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.366951: Initiating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.366980: Sending TCP request to stream 10.19.41.54:88
> [2010] 1504979429.369031: Received answer (308 bytes) from stream 10.19.41.54:88
> [2010] 1504979429.369038: Terminating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.369064: Received error from KDC: -1765328359/Additional pre-authentication required
> [2010] 1504979429.369083: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
> [2010] 1504979429.369094: Selected etype info: etype aes256-cts, salt "g3,cY9a!,]I#?!mP", params ""
> [2010] 1504979429.369096: Received cookie: MIT
> [2010] 1504979429.369111: PKINIT client has no configured identity; giving up
> [2010] 1504979429.369123: Preauth module pkinit (147) (info) returned: 0/Success
> [2010] 1504979429.369130: PKINIT client has no configured identity; giving up
> [2010] 1504979429.369134: Preauth module pkinit (16) (real) returned: 22/Invalid argument
> [2010] 1504979429.369139: PKINIT client has no configured identity; giving up
> [2010] 1504979429.369143: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> [2010] 1504979429.369148: PKINIT client has no configured identity; giving up
> [2010] 1504979429.369157: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> Password for [e-mail]: 
> [2010] 1504979429.377997: AS key obtained for encrypted timestamp: aes256-cts/15DF
> [2010] 1504979429.378038: Encrypted timestamp (for 1504979429.377885): plain 301AA011180F32303137303930393137353032395AA105020305C41D, encrypted 724A100FDF786F4B706BEF70A1017CABF3825B16F5111CE381D1C02ECFAF081A75CB0E1B0140709720FE77E1C124344DDFF788DDA1DBBD0D
> [2010] 1504979429.378048: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
> [2010] 1504979429.378051: Produced preauth for next request: 133, 2
> [2010] 1504979429.378060: Sending request (273 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.378117: Initiating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.378151: Sending TCP request to stream 10.19.41.54:88
> [2010] 1504979429.380629: Received answer (744 bytes) from stream 10.19.41.54:88
> [2010] 1504979429.380650: Terminating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.380684: Processing preauth types: 19
> [2010] 1504979429.380690: Selected etype info: etype aes256-cts, salt "g3,cY9a!,]I#?!mP", params ""
> [2010] 1504979429.380693: Produced preauth for next request: (empty)
> [2010] 1504979429.380704: AS key determined by preauth: aes256-cts/15DF
> [2010] 1504979429.380753: Decrypted AS reply; session key is: aes256-cts/0DC0
> [2010] 1504979429.380766: FAST negotiation: available
> [2010] 1504979429.380792: Attempting password change; 3 tries remaining
> Password expired.  You must change it now.
> Enter new password: 
> Enter it again: 
> [2010] 1504979429.380839: Creating authenticator for [e-mail] -> kadmin/[e-mail], seqnum 0, subkey aes256-cts/25FC, session key aes256-cts/0DC0
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[5]
> [sssd_krb5_locator] addr[10.19.41.54:464] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[5]
> [sssd_krb5_locator] addr[10.19.41.54:464] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.380951: Sending initial UDP request to dgram 10.19.41.54:464
> [2010] 1504979429.412096: Received answer (236 bytes) from dgram 10.19.41.54:464
> [2010] 1504979429.412179: Read AP-REP, time 1504979429.380843, subkey aes256-cts/25FC, seqnum 534540384
> [2010] 1504979429.412213: Getting initial TGT with changed password
> [2010] 1504979429.412220: Getting initial credentials for [e-mail]
> [2010] 1504979429.412279: Sending request (183 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.413245: Initiating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.413512: Sending TCP request to stream 10.19.41.54:88
> [2010] 1504979429.416335: Received answer (313 bytes) from stream 10.19.41.54:88
> [2010] 1504979429.416343: Terminating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.416387: Received error from KDC: -1765328359/Additional pre-authentication required
> [2010] 1504979429.416421: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
> [2010] 1504979429.416426: Selected etype info: etype aes256-cts, salt "Py@@RV$)_8syq{7@", params ""
> [2010] 1504979429.416428: Received cookie: MIT
> [2010] 1504979429.416445: PKINIT client has no configured identity; giving up
> [2010] 1504979429.416458: Preauth module pkinit (147) (info) returned: 0/Success
> [2010] 1504979429.416467: PKINIT client has no configured identity; giving up
> [2010] 1504979429.416472: Preauth module pkinit (16) (real) returned: 22/Invalid argument
> [2010] 1504979429.416478: PKINIT client has no configured identity; giving up
> [2010] 1504979429.416482: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> [2010] 1504979429.416487: PKINIT client has no configured identity; giving up
> [2010] 1504979429.416491: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> [2010] 1504979429.424898: AS key obtained for encrypted timestamp: aes256-cts/D927
> [2010] 1504979429.424928: Encrypted timestamp (for 1504979429.424460): plain 301AA011180F32303137303930393137353032395AA1050203067A0C, encrypted A06565BC61A85C400D1C6A392DEE704D8597EA81FCC3FF9CBCAE7FA7E65F9CB145DC92C2985DCA86280176D9B6F4AF3A0CD2F95C097A842D
> [2010] 1504979429.424935: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
> [2010] 1504979429.424938: Produced preauth for next request: 133, 2
> [2010] 1504979429.424946: Sending request (278 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] Found [10.19.41.54] in [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST].
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kpasswdinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] reading kpasswd address failed, using kdc address.
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[2] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[2]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_realm[TESTRELM.TEST] requested realm[TESTRELM.TEST] family[0] socktype[1] locate_service[2]
> [sssd_krb5_locator] addr[10.19.41.54:88] family[2] socktype[1]
> [sssd_krb5_locator] [10.19.41.54] used
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2010] 1504979429.424998: Initiating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.425026: Sending TCP request to stream 10.19.41.54:88
> [2010] 1504979429.430744: Received answer (755 bytes) from stream 10.19.41.54:88
> [2010] 1504979429.430752: Terminating TCP connection to stream 10.19.41.54:88
> [2010] 1504979429.430796: Processing preauth types: 19
> [2010] 1504979429.430803: Selected etype info: etype aes256-cts, salt "Py@@RV$)_8syq{7@", params ""
> [2010] 1504979429.430807: Produced preauth for next request: (empty)
> [2010] 1504979429.430812: AS key determined by preauth: aes256-cts/D927
> [2010] 1504979429.430840: Decrypted AS reply; session key is: aes256-cts/B4D9
> [2010] 1504979429.430849: FAST negotiation: available
> [2010] 1504979429.430871: Initializing KEYRING:persistent:0:0 with default princ [e-mail]
> [2010] 1504979429.430918: Storing [e-mail] -> krbtgt/[e-mail] in KEYRING:persistent:0:0
> [2010] 1504979429.430949: Storing config in KEYRING:persistent:0:0 for krbtgt/[e-mail]: fast_avail: yes
> [2010] 1504979429.430962: Storing [e-mail] -> krb5_ccache_conf_data/fast_avail/krbtgt/[e-mail]@X-CACHECONF: in KEYRING:persistent:0:0
> [2010] 1504979429.430988: Storing config in KEYRING:persistent:0:0 for krbtgt/[e-mail]: pa_type: 2
> [2010] 1504979429.430996: Storing [e-mail] -> krb5_ccache_conf_data/pa_type/krbtgt/[e-mail]@X-CACHECONF: in KEYRING:persistent:0:0
> Authenticated to Kerberos v5
> Default principal: [e-mail]
> :: [ 13:50:29 ] :: kinit as selfservuser1 with new password passw0rd1 was successful.
> Added user "selfservuser1"
>
> User login: selfservuser1
>   First name: first
>   Last name: last
>   Full name: first last
>   Display name: first last
>   Initials: fl
>   Home directory: /home/selfservuser1
>   GECOS: first last
>   Login shell: /bin/sh
>   Principal name: [e-mail]
>   Principal alias: [e-mail]
>   Email address: [e-mail]
>   UID: 1033600021
>   GID: 1033600021
>   Password: True
>   Member of groups: ipausers
>   Kerberos keys available: True
> :: [   PASS   ] :: add test user account (Expected 0, got 0)
> :: [  BEGIN   ] :: Running 'FirstKinitAs selfservuser1 [e-mail] passw0rd1'
> [2085] 1504880246.717409: Destroying ccache KEYRING:persistent:0:0
> Using default cache: persistent:0:0
> Using principal: [e-mail]
> [2087] 1504880246.723854: Getting initial credentials for [e-mail]
> [2087] 1504880246.725923: Sending request (183 bytes) to TESTRELM.TEST
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.726052: Resolving hostname kvm-02-guest23.testrelm.test
> [2087] 1504880246.726388: Initiating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.726467: Sending TCP request to stream 10.16.68.129:88
> [2087] 1504880246.728536: Received answer (186 bytes) from stream 10.16.68.129:88
> [2087] 1504880246.728544: Terminating TCP connection to stream 10.16.68.129:88
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.728603: Response was from master KDC
> [2087] 1504880246.728636: Received error from KDC: -1765328361/Password has expired
> [2087] 1504880246.728655: Principal expired; getting changepw ticket
> [2087] 1504880246.728661: Getting initial credentials for [e-mail]
> [2087] 1504880246.728676: Setting initial creds service to kadmin/changepw
> [2087] 1504880246.728693: Sending request (178 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.728709: Resolving hostname kvm-02-guest23.testrelm.test
> [2087] 1504880246.728780: Initiating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.728811: Sending TCP request to stream 10.16.68.129:88
> [2087] 1504880246.730875: Received answer (308 bytes) from stream 10.16.68.129:88
> [2087] 1504880246.730882: Terminating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.730906: Received error from KDC: -1765328359/Additional pre-authentication required
> [2087] 1504880246.730925: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
> [2087] 1504880246.730936: Selected etype info: etype aes256-cts, salt "IW9`+Bl+'dxuYHbk", params ""
> [2087] 1504880246.730939: Received cookie: MIT
> [2087] 1504880246.730952: PKINIT client has no configured identity; giving up
> [2087] 1504880246.730965: Preauth module pkinit (147) (info) returned: 0/Success
> [2087] 1504880246.730971: PKINIT client has no configured identity; giving up
> [2087] 1504880246.730982: Preauth module pkinit (16) (real) returned: 22/Invalid argument
> [2087] 1504880246.730987: PKINIT client has no configured identity; giving up
> [2087] 1504880246.730991: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> [2087] 1504880246.730995: PKINIT client has no configured identity; giving up
> [2087] 1504880246.730999: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> Password for [e-mail]: 
> [2087] 1504880246.740078: AS key obtained for encrypted timestamp: aes256-cts/499B
> [2087] 1504880246.740125: Encrypted timestamp (for 1504880246.739952): plain 301AA011180F32303137303930383134313732365AA10502030B4A70, encrypted B551CD21FE48C30DA246AB740E90048E2A38C4288EB6DEFD9D139937EFFACC074D1EDD786E1E201BB1690EF483BECD0EC98387E62DA2E274
> [2087] 1504880246.740153: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
> [2087] 1504880246.740156: Produced preauth for next request: 133, 2
> [2087] 1504880246.740169: Sending request (273 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.740201: Resolving hostname kvm-02-guest23.testrelm.test
> [2087] 1504880246.740342: Initiating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.740393: Sending TCP request to stream 10.16.68.129:88
> [2087] 1504880246.743192: Received answer (744 bytes) from stream 10.16.68.129:88
> [2087] 1504880246.743199: Terminating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.743233: Processing preauth types: 19
> [2087] 1504880246.743240: Selected etype info: etype aes256-cts, salt "IW9`+Bl+'dxuYHbk", params ""
> [2087] 1504880246.743243: Produced preauth for next request: (empty)
> [2087] 1504880246.743249: AS key determined by preauth: aes256-cts/499B
> [2087] 1504880246.743285: Decrypted AS reply; session key is: aes256-cts/756D
> [2087] 1504880246.743325: FAST negotiation: available
> [2087] 1504880246.743360: Attempting password change; 3 tries remaining
> Password expired.  You must change it now.
> Enter new password: 
> Enter it again: 
> [2087] 1504880246.743415: Creating authenticator for [e-mail] -> kadmin/[e-mail], seqnum 0, subkey aes256-cts/583E, session key aes256-cts/756D
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.743980: Resolving hostname ibm-x3650m4-01-vm-05.testrelm.test.
> [2087] 1504880246.744368: Sending initial UDP request to dgram 2620:52:0:102f:5054:1ff:fe3c:e12d:464
> [2087] 1504880246.813550: Received answer (248 bytes) from dgram 2620:52:0:102f:5054:1ff:fe3c:e12d:464
> [2087] 1504880246.813683: Read AP-REP, time 1504880246.743419, subkey aes256-cts/583E, seqnum 1071928275
> [2087] 1504880246.813717: Getting initial TGT with changed password
> [2087] 1504880246.813723: Getting initial credentials for [e-mail]
> [2087] 1504880246.813784: Sending request (183 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [2087] 1504880246.813835: Resolving hostname kvm-02-guest23.testrelm.test
> [2087] 1504880246.814002: Initiating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.814048: Sending TCP request to stream 10.16.68.129:88
> [2087] 1504880246.816774: Received answer (186 bytes) from stream 10.16.68.129:88
> [2087] 1504880246.816781: Terminating TCP connection to stream 10.16.68.129:88
> [2087] 1504880246.816811: Received error from KDC: -1765328361/Password has expired
> kinit: Password has expired while getting initial credentials
> klist: Credentials cache keyring 'persistent:0:0' not found
> :: [ 10:17:26 ] :: ERROR: kinit as selfservuser1 with new password passw0rd1 failed.
> :: [   FAIL   ] :: Command 'FirstKinitAs selfservuser1 [e-mail] passw0rd1' (Expected 0, got 1)
> sssd-devel mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]

[Lukas Slebodnik]

On (12/09/17 18:44), Sumit Bose wrote:
> On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> > ehlo,
> >
> > I realized that it might be better to discuss it here rather then in
> > pull requests because it seems to be related to two different commits.
> >
> > I will describe a test case on master with already created replica on another
> > host.
> >
> > kinit as admin
> >   // create user with dummy password
> >
> > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> >                              --password
> >
> > // adding sleep think that first kinit hits slave sometimes and the user is
> >   // not replicated yet.
> >
> > sleep 2
> >
> > FirstKinitAs $login $dummypw $password
> >
> > FirstKinitAs is a bash function which change initial password
> > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> >
> > Such test works reliably with 1.15.3 and kinit always talk to local master
> > (I didn't try to remove sleep 2)
> >
> > But situation changed a little bit with git master due to following commits
> > IPA: Only generate kdcinfo files on clients
> > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
>
> Do you have the /etc/krb5.conf available from the host where the test
> failed. The above patch was written with the assumption that
> /etc/krb5.conf on the IPA server points to the server itself as
> ipa-server-install creates it:
>
> [realms]
> IPA.DEVEL = {
>  kdc = ipa-devel.ipa.devel:88
>  master_kdc = ipa-devel.ipa.devel:88
>  admin_server = ipa-devel.ipa.devel:749
>  default_domain = ipa.devel
>  pkinit_anchors = FILE:/etc/ipa/ca.crt
> }
>
> Currently I would assume that at least admin_server is missing.
> > localauth plugin: change return code of sss_an2ln
> > https://pagure.io/SSSD/sssd/c/3f94a979eebd1c9496b49b4e07b7823550dec97e
>
> I'm a bit surprised here because it is not clear to me where during the
> test an2ln is used. But if it is the case it might point to an issue at
> a different place because the old return code was wrong according to the
> documentation of the plugin.

I probably mixed versions of packages when I ran test. Because reverting
patch for krb5_localauth plugin did not help and it still fails

--------------------------
Added user "selfservuser1"
--------------------------
  User login: selfservuser1
  First name: first
  Last name: last
  Full name: first last
  Display name: first last
  Initials: fl
  Home directory: /home/selfservuser1
  GECOS: first last
  Login shell: /bin/sh
  Principal name: [e-mail]
  Principal alias: [e-mail]
  Email address: [e-mail]
  UID: 716000021
  GID: 716000021
  Password: True
  Member of groups: ipausers
  Kerberos keys available: True
:: [   PASS   ] :: add test user account (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'FirstKinitAs selfservuser1 [e-mail] passw0rd1'
[1836] 1505231102.633534: Destroying ccache KEYRING:persistent:0:0
Using default cache: persistent:0:0
Using principal: [e-mail]
[1838] 1505231102.639333: Getting initial credentials for [e-mail]
[1838] 1505231102.641609: Sending request (183 bytes) to TESTRELM.TEST
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.641757: Resolving hostname bkr-hv03-guest38.testrelm.test
[1838] 1505231102.642102: Initiating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.642170: Sending TCP request to stream 10.19.41.68:88
[1838] 1505231102.644813: Received answer (186 bytes) from stream 10.19.41.68:88
[1838] 1505231102.644822: Terminating TCP connection to stream 10.19.41.68:88
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.644878: Response was from master KDC
[1838] 1505231102.644897: Received error from KDC: -1765328361/Password has expired
[1838] 1505231102.644915: Principal expired; getting changepw ticket
[1838] 1505231102.644921: Getting initial credentials for [e-mail]
[1838] 1505231102.644936: Setting initial creds service to kadmin/changepw
[1838] 1505231102.644954: Sending request (178 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.644973: Resolving hostname bkr-hv03-guest38.testrelm.test
[1838] 1505231102.645055: Initiating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.645102: Sending TCP request to stream 10.19.41.68:88
[1838] 1505231102.647338: Received answer (308 bytes) from stream 10.19.41.68:88
[1838] 1505231102.647346: Terminating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.647382: Received error from KDC: -1765328359/Additional pre-authentication required
[1838] 1505231102.647404: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
[1838] 1505231102.647415: Selected etype info: etype aes256-cts, salt ",U-"2{X22zFHoWcb", params ""
[1838] 1505231102.647418: Received cookie: MIT
[1838] 1505231102.647434: PKINIT client has no configured identity; giving up
[1838] 1505231102.647447: Preauth module pkinit (147) (info) returned: 0/Success
[1838] 1505231102.647454: PKINIT client has no configured identity; giving up
[1838] 1505231102.647459: Preauth module pkinit (16) (real) returned: 22/Invalid argument
[1838] 1505231102.647464: PKINIT client has no configured identity; giving up
[1838] 1505231102.647468: Preauth module pkinit (14) (real) returned: 22/Invalid argument
[1838] 1505231102.647474: PKINIT client has no configured identity; giving up
[1838] 1505231102.647478: Preauth module pkinit (14) (real) returned: 22/Invalid argument
Password for [e-mail]: 
[1838] 1505231102.656744: AS key obtained for encrypted timestamp: aes256-cts/A66D
[1838] 1505231102.656785: Encrypted timestamp (for 1505231102.656605): plain 301AA011180F32303137303931323135343530325AA10502030A04DD, encrypted 85E9E81C445DF84C3C059D350C388044D722FEB89EC67C3C7016E6CD6E588BE004A9556F156769B74E32CE3EC2175D58AAFB01D51249D4D8
[1838] 1505231102.656795: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
[1838] 1505231102.656798: Produced preauth for next request: 133, 2
[1838] 1505231102.656808: Sending request (273 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.656831: Resolving hostname bkr-hv03-guest38.testrelm.test
[1838] 1505231102.656914: Initiating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.656950: Sending TCP request to stream 10.19.41.68:88
[1838] 1505231102.659730: Received answer (744 bytes) from stream 10.19.41.68:88
[1838] 1505231102.659738: Terminating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.659771: Processing preauth types: 19
[1838] 1505231102.659777: Selected etype info: etype aes256-cts, salt ",U-"2{X22zFHoWcb", params ""
[1838] 1505231102.659781: Produced preauth for next request: (empty)
[1838] 1505231102.659787: AS key determined by preauth: aes256-cts/A66D
[1838] 1505231102.659825: Decrypted AS reply; session key is: aes256-cts/925B
[1838] 1505231102.659838: FAST negotiation: available
[1838] 1505231102.659864: Attempting password change; 3 tries remaining
Password expired.  You must change it now.
Enter new password: 
Enter it again: 
[1838] 1505231102.659911: Creating authenticator for [e-mail] -> kadmin/[e-mail], seqnum 0, subkey aes256-cts/E008, session key aes256-cts/925B
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.660554: Resolving hostname kvm-02-guest03.testrelm.test.
[1838] 1505231102.660988: Sending initial UDP request to dgram 2620:52:0:1040:5054:ff:fe71:6fb1:464
[1838] 1505231102.689233: Received answer (248 bytes) from dgram 2620:52:0:1040:5054:ff:fe71:6fb1:464
[1838] 1505231102.689284: Read AP-REP, time 1505231102.659915, subkey aes256-cts/E008, seqnum 342299389
[1838] 1505231102.689308: Getting initial TGT with changed password
[1838] 1505231102.689312: Getting initial credentials for [e-mail]
[1838] 1505231102.689357: Sending request (183 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1838] 1505231102.689388: Resolving hostname bkr-hv03-guest38.testrelm.test
[1838] 1505231102.689477: Initiating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.689517: Sending TCP request to stream 10.19.41.68:88
[1838] 1505231102.691967: Received answer (186 bytes) from stream 10.19.41.68:88
[1838] 1505231102.691976: Terminating TCP connection to stream 10.19.41.68:88
[1838] 1505231102.692010: Received error from KDC: -1765328361/Password has expired
kinit: Password has expired while getting initial credentials
klist: Credentials cache keyring 'persistent:0:0' not found
:: [ 11:45:02 ] :: ERROR: kinit as selfservuser1 with new password passw0rd1 failed.
:: [   FAIL   ] :: Command 'FirstKinitAs selfservuser1 [e-mail] passw0rd1' (Expected 0, got 1)
[1852] 1505231102.895334: Destroying ccache KEYRING:persistent:0:0
selfservuser1
[1854] 1505231102.900444: Getting initial credentials for [e-mail]
[1854] 1505231102.902589: Sending request (175 bytes) to TESTRELM.TEST
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1854] 1505231102.902739: Resolving hostname bkr-hv03-guest38.testrelm.test
[1854] 1505231102.903091: Initiating TCP connection to stream 10.19.41.68:88
[1854] 1505231102.903159: Sending TCP request to stream 10.19.41.68:88
[1854] 1505231102.909061: Received answer (305 bytes) from stream 10.19.41.68:88
[1854] 1505231102.909075: Terminating TCP connection to stream 10.19.41.68:88
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1854] 1505231102.909144: Response was from master KDC
[1854] 1505231102.909161: Received error from KDC: -1765328359/Additional pre-authentication required
[1854] 1505231102.909194: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
[1854] 1505231102.909203: Selected etype info: etype aes256-cts, salt "SkP  Io5?\bg.^vG", params ""
[1854] 1505231102.909206: Received cookie: MIT
[1854] 1505231102.909221: PKINIT client has no configured identity; giving up
[1854] 1505231102.909235: Preauth module pkinit (147) (info) returned: 0/Success
[1854] 1505231102.909242: PKINIT client has no configured identity; giving up
[1854] 1505231102.909247: Preauth module pkinit (16) (real) returned: 22/Invalid argument
[1854] 1505231102.909253: PKINIT client has no configured identity; giving up
[1854] 1505231102.909258: Preauth module pkinit (14) (real) returned: 22/Invalid argument
[1854] 1505231102.909280: PKINIT client has no configured identity; giving up
[1854] 1505231102.909286: Preauth module pkinit (14) (real) returned: 22/Invalid argument
[1854] 1505231102.918366: AS key obtained for encrypted timestamp: aes256-cts/BC4B
[1854] 1505231102.918408: Encrypted timestamp (for 1505231102.917977): plain 301AA011180F32303137303931323135343530325AA10502030E01D9, encrypted 0B89C878A11B01A30D769374C002AFDB0C9F8E992F5D5A78E65FCCD201FC38DC731D4845AE1CBD524DD56416C4CCA991E2EA44575931B7B4
[1854] 1505231102.918419: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
[1854] 1505231102.918422: Produced preauth for next request: 133, 2
[1854] 1505231102.918433: Sending request (270 bytes) to TESTRELM.TEST
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1854] 1505231102.918455: Resolving hostname bkr-hv03-guest38.testrelm.test
[1854] 1505231102.918570: Initiating TCP connection to stream 10.19.41.68:88
[1854] 1505231102.919095: Sending TCP request to stream 10.19.41.68:88
[1854] 1505231102.923547: Received answer (738 bytes) from stream 10.19.41.68:88
[1854] 1505231102.923560: Terminating TCP connection to stream 10.19.41.68:88
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[1854] 1505231102.923612: Response was from master KDC
[1854] 1505231102.923640: Processing preauth types: 19
[1854] 1505231102.923661: Selected etype info: etype aes256-cts, salt "SkP  Io5?\bg.^vG", params ""
[1854] 1505231102.923668: Produced preauth for next request: (empty)
[1854] 1505231102.923674: AS key determined by preauth: aes256-cts/BC4B
[1854] 1505231102.923714: Decrypted AS reply; session key is: aes256-cts/B5A5
[1854] 1505231102.923727: FAST negotiation: available
[1854] 1505231102.923744: Initializing KEYRING:persistent:0:0 with default princ [e-mail]
[1854] 1505231102.923779: Storing [e-mail] -> krbtgt/[e-mail] in KEYRING:persistent:0:0
[1854] 1505231102.923814: Storing config in KEYRING:persistent:0:0 for krbtgt/[e-mail]: fast_avail: yes
[1854] 1505231102.923826: Storing [e-mail] -> krb5_ccache_conf_data/fast_avail/krbtgt/[e-mail]@X-CACHECONF: in KEYRING:persistent:0:0
[1854] 1505231102.923850: Storing config in KEYRING:persistent:0:0 for krbtgt/[e-mail]: pa_type: 2
[1854] 1505231102.923858: Storing [e-mail] -> krb5_ccache_conf_data/pa_type/krbtgt/[e-mail]@X-CACHECONF: in KEYRING:persistent:0:0
:: [   FAIL   ] :: Command 'create_ipauser selfservuser1 first last passw0rd1' (Expected 0, got 1)

LS

[Lukas Slebodnik]

On (12/09/17 18:44), Sumit Bose wrote:
> On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> > ehlo,
> >
> > I realized that it might be better to discuss it here rather then in
> > pull requests because it seems to be related to two different commits.
> >
> > I will describe a test case on master with already created replica on another
> > host.
> >
> > kinit as admin
> >   // create user with dummy password
> >
> > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> >                              --password
> >
> > // adding sleep think that first kinit hits slave sometimes and the user is
> >   // not replicated yet.
> >
> > sleep 2
> >
> > FirstKinitAs $login $dummypw $password
> >
> > FirstKinitAs is a bash function which change initial password
> > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> >
> > Such test works reliably with 1.15.3 and kinit always talk to local master
> > (I didn't try to remove sleep 2)
> >
> > But situation changed a little bit with git master due to following commits
> > IPA: Only generate kdcinfo files on clients
> > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
>
> Do you have the /etc/krb5.conf available from the host where the test
> failed. The above patch was written with the assumption that
> /etc/krb5.conf on the IPA server points to the server itself as
> ipa-server-install creates it:
>
> [realms]
> IPA.DEVEL = {
>  kdc = ipa-devel.ipa.devel:88
>  master_kdc = ipa-devel.ipa.devel:88
>  admin_server = ipa-devel.ipa.devel:749
>  default_domain = ipa.devel
>  pkinit_anchors = FILE:/etc/ipa/ca.crt
> }
>
> Currently I would assume that at least admin_server is missing.

Here you are.
local master: kvm-02-guest11.testrelm.test
replica: bkr-hv01-guest19.testrelm.test

[root@kvm-02-guest11 ~]# cat /etc/krb5.conf
includedir /etc/krb5.conf.d/
includedir /var/lib/sss/pubconf/krb5.include.d/

[logging]
 default = FILE:/var/log/krb5libs.log
 kdc = FILE:/var/log/krb5kdc.log
 admin_server = FILE:/var/log/kadmind.log

[libdefaults]
 default_realm = TESTRELM.TEST
 dns_lookup_realm = false
 dns_lookup_kdc = true
 rdns = false
 ticket_lifetime = 24h
 forwardable = true
 udp_preference_limit = 0
 default_ccache_name = KEYRING:persistent:%{uid}

[realms]
 TESTRELM.TEST = {
  kdc = kvm-02-guest11.testrelm.test:88
  master_kdc = kvm-02-guest11.testrelm.test:88
  admin_server = kvm-02-guest11.testrelm.test:749
  default_domain = testrelm.test
  pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
  pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
}

[domain_realm]
 .testrelm.test = TESTRELM.TEST
 testrelm.test = TESTRELM.TEST
 kvm-02-guest11.testrelm.test = TESTRELM.TEST

[dbmodules]
  TESTRELM.TEST = {
    db_library = ipadb.so
  }

[root@kvm-02-guest11 ~]# ls /etc/krb5.conf.d/
ipa-certauth
[root@kvm-02-guest11 ~]# cat /etc/krb5.conf.d/ipa-certauth
[plugins]
 certauth = {
  module = ipakdb:kdb/ipadb.so
  enable_only = ipakdb
 }

[root@kvm-02-guest11 ~]# ls /var/lib/sss/pubconf/krb5.include.d/
domain_realm_testrelm_test  krb5_libdefaults  localauth_plugin
[root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/domain_realm_testrelm_test
[domain_realm]
[root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/krb5_libdefaults
[libdefaults]
 canonicalize = true
[root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/localauth_plugin
[plugins]
 localauth = {
  module = sssd:/usr/lib64/sssd/modules/sssd_krb5_localauth_plugin.so
 }

-------------------------
Added user "delegatuser2"
-------------------------
  User login: delegatuser2
  First name: first
  Last name: last
  Full name: first last
  Display name: first last
  Initials: fl
  Home directory: /home/delegatuser2
  GECOS: first last
  Login shell: /bin/sh
  Principal name: [e-mail]
  Principal alias: [e-mail]
  Email address: [e-mail]
  UID: 1622800023
  GID: 1622800023
  Password: True
  Member of groups: ipausers
  Kerberos keys available: True
:: [   PASS   ] :: add test user account (Expected 0, got 0)
:: [  BEGIN   ] :: Running 'FirstKinitAs delegatuser2 [e-mail] passw0rd1'
[3190] 1505997473.156106: Destroying ccache KEYRING:persistent:0:0
Using default cache: persistent:0:0
Using principal: [e-mail]
[3192] 1505997473.161781: Getting initial credentials for [e-mail]
[3192] 1505997473.163737: Sending request (182 bytes) to TESTRELM.TEST
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.163848: Resolving hostname kvm-02-guest11.testrelm.test
[3192] 1505997473.164170: Initiating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.164235: Sending TCP request to stream 10.16.68.117:88
[3192] 1505997473.165916: Received answer (185 bytes) from stream 10.16.68.117:88
[3192] 1505997473.165924: Terminating TCP connection to stream 10.16.68.117:88
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.165968: Response was from master KDC
[3192] 1505997473.166001: Received error from KDC: -1765328361/Password has expired
[3192] 1505997473.166019: Principal expired; getting changepw ticket
[3192] 1505997473.166025: Getting initial credentials for [e-mail]
[3192] 1505997473.166040: Setting initial creds service to kadmin/changepw
[3192] 1505997473.166057: Sending request (177 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.166074: Resolving hostname kvm-02-guest11.testrelm.test
[3192] 1505997473.166175: Initiating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.166212: Sending TCP request to stream 10.16.68.117:88
[3192] 1505997473.167923: Received answer (307 bytes) from stream 10.16.68.117:88
[3192] 1505997473.167930: Terminating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.167956: Received error from KDC: -1765328359/Additional pre-authentication required
[3192] 1505997473.167975: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
[3192] 1505997473.167986: Selected etype info: etype aes256-cts, salt "k^pE1RcGTiTV+B^z", params ""
[3192] 1505997473.167989: Received cookie: MIT
[3192] 1505997473.168002: PKINIT client has no configured identity; giving up
[3192] 1505997473.168014: Preauth module pkinit (147) (info) returned: 0/Success
[3192] 1505997473.168020: PKINIT client has no configured identity; giving up
[3192] 1505997473.168032: Preauth module pkinit (16) (real) returned: 22/Invalid argument
[3192] 1505997473.168037: PKINIT client has no configured identity; giving up
[3192] 1505997473.168041: Preauth module pkinit (14) (real) returned: 22/Invalid argument
[3192] 1505997473.168046: PKINIT client has no configured identity; giving up
[3192] 1505997473.168049: Preauth module pkinit (14) (real) returned: 22/Invalid argument
Password for [e-mail]: 
[3192] 1505997473.178371: AS key obtained for encrypted timestamp: aes256-cts/B60B
[3192] 1505997473.178425: Encrypted timestamp (for 1505997473.178262): plain 301AA011180F32303137303932313132333735335AA105020302B856, encrypted 75BDE01CE518AA302EF19F306BFD673D9826B688CDC279D0612EBAC58F427D18B83396D82D26401BF17C982B422B2C990B8E50B96760B4FA
[3192] 1505997473.178455: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
[3192] 1505997473.178459: Produced preauth for next request: 133, 2
[3192] 1505997473.178472: Sending request (272 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.178503: Resolving hostname kvm-02-guest11.testrelm.test
[3192] 1505997473.178645: Initiating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.178728: Sending TCP request to stream 10.16.68.117:88
[3192] 1505997473.181321: Received answer (742 bytes) from stream 10.16.68.117:88
[3192] 1505997473.181330: Terminating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.181369: Processing preauth types: 19
[3192] 1505997473.181376: Selected etype info: etype aes256-cts, salt "k^pE1RcGTiTV+B^z", params ""
[3192] 1505997473.181380: Produced preauth for next request: (empty)
[3192] 1505997473.181386: AS key determined by preauth: aes256-cts/B60B
[3192] 1505997473.181426: Decrypted AS reply; session key is: aes256-cts/0A8F
[3192] 1505997473.181440: FAST negotiation: available
[3192] 1505997473.181489: Attempting password change; 3 tries remaining
Password expired.  You must change it now.
Enter new password: 
Enter it again: 
[3192] 1505997473.181542: Creating authenticator for [e-mail] -> kadmin/[e-mail], seqnum 0, subkey aes256-cts/4B37, session key aes256-cts/0A8F
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.182186: Resolving hostname bkr-hv01-guest19.testrelm.test.
[3192] 1505997473.182599: Sending initial UDP request to dgram 2620:52:0:1329:216:3eff:fe27:7207:464
[3192] 1505997473.220273: Received answer (248 bytes) from dgram 2620:52:0:1329:216:3eff:fe27:7207:464
[3192] 1505997473.220380: Read AP-REP, time 1505997473.181546, subkey aes256-cts/4B37, seqnum 256549514
[3192] 1505997473.220416: Getting initial TGT with changed password
[3192] 1505997473.220423: Getting initial credentials for [e-mail]
[3192] 1505997473.220468: Sending request (182 bytes) to TESTRELM.TEST (master)
[sssd_krb5_locator] sssd_krb5_locator_init called
[sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
[sssd_krb5_locator] get_krb5info failed.
[sssd_krb5_locator] sssd_krb5_locator_close called
[3192] 1505997473.220502: Resolving hostname kvm-02-guest11.testrelm.test
[3192] 1505997473.220620: Initiating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.220667: Sending TCP request to stream 10.16.68.117:88
[3192] 1505997473.222921: Received answer (185 bytes) from stream 10.16.68.117:88
[3192] 1505997473.222930: Terminating TCP connection to stream 10.16.68.117:88
[3192] 1505997473.222979: Received error from KDC: -1765328361/Password has expired
kinit: Password has expired while getting initial credentials
klist: Credentials cache keyring 'persistent:0:0' not found
:: [ 08:37:53 ] :: ERROR: kinit as delegatuser2 with new password passw0rd1 failed.
:: [   FAIL   ] :: Command 'FirstKinitAs delegatuser2 [e-mail] passw0rd1' (Expected 0, got 1)

[Simo Sorce]

On Thu, 2017-09-21 at 16:52 +0200, Lukas Slebodnik wrote:
> Here you are.
> local master: kvm-02-guest11.testrelm.test
> replica: bkr-hv01-guest19.testrelm.test
>
> [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> includedir /etc/krb5.conf.d/
> includedir /var/lib/sss/pubconf/krb5.include.d/
>
> [logging]
>  default = FILE:/var/log/krb5libs.log
>  kdc = FILE:/var/log/krb5kdc.log
>  admin_server = FILE:/var/log/kadmind.log
>
> [libdefaults]
>  default_realm = TESTRELM.TEST
>  dns_lookup_realm = false
>  dns_lookup_kdc = true

This ^^^^ sounds wrong on a master

Simo.

[Sumit Bose]

On Thu, Sep 21, 2017 at 11:23:20AM -0400, Simo Sorce wrote:
> On Thu, 2017-09-21 at 16:52 +0200, Lukas Slebodnik wrote:
> > Here you are.
> > local master: kvm-02-guest11.testrelm.test
> > replica: bkr-hv01-guest19.testrelm.test
> >
> > [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> > includedir /etc/krb5.conf.d/
> > includedir /var/lib/sss/pubconf/krb5.include.d/
> >
> > [logging]
> >  default = FILE:/var/log/krb5libs.log
> >  kdc = FILE:/var/log/krb5kdc.log
> >  admin_server = FILE:/var/log/kadmind.log
> >
> > [libdefaults]
> >  default_realm = TESTRELM.TEST
> >  dns_lookup_realm = false
> >  dns_lookup_kdc = true
>
> This ^^^^ sounds wrong on a master

no, you need this to find any AD DC in a trusted forest.

bye,
Sumit
> Simo.
>
> -- 
> Simo Sorce
> Sr. Principal Software Engineer
> Red Hat, Inc

[Simo Sorce]

On Thu, 2017-09-21 at 17:56 +0200, Sumit Bose wrote:
> On Thu, Sep 21, 2017 at 11:23:20AM -0400, Simo Sorce wrote:
> > On Thu, 2017-09-21 at 16:52 +0200, Lukas Slebodnik wrote:
> > > Here you are.
> > > local master: kvm-02-guest11.testrelm.test
> > > replica: bkr-hv01-guest19.testrelm.test
> > >
> > > [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> > > includedir /etc/krb5.conf.d/
> > > includedir /var/lib/sss/pubconf/krb5.include.d/
> > >
> > > [logging]
> > >  default = FILE:/var/log/krb5libs.log
> > >  kdc = FILE:/var/log/krb5kdc.log
> > >  admin_server = FILE:/var/log/kadmind.log
> > >
> > > [libdefaults]
> > >  default_realm = TESTRELM.TEST
> > >  dns_lookup_realm = false
> > >  dns_lookup_kdc = true
> >
> > This ^^^^ sounds wrong on a master
>
> no, you need this to find any AD DC in a trusted forest.

Shouldn't SSSD do that for us via proper site discovery ?

Simo.
> bye,
> Sumit
> > Simo.
> >
> > -- 
> > Simo Sorce
> > Sr. Principal Software Engineer
> > Red Hat, Inc

[Sumit Bose]

On Thu, Sep 21, 2017 at 01:07:23PM -0400, Simo Sorce wrote:
> On Thu, 2017-09-21 at 17:56 +0200, Sumit Bose wrote:
> > On Thu, Sep 21, 2017 at 11:23:20AM -0400, Simo Sorce wrote:
> > > On Thu, 2017-09-21 at 16:52 +0200, Lukas Slebodnik wrote:
> > > > Here you are.
> > > > local master: kvm-02-guest11.testrelm.test
> > > > replica: bkr-hv01-guest19.testrelm.test
> > > >
> > > > [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> > > > includedir /etc/krb5.conf.d/
> > > > includedir /var/lib/sss/pubconf/krb5.include.d/
> > > >
> > > > [logging]
> > > >  default = FILE:/var/log/krb5libs.log
> > > >  kdc = FILE:/var/log/krb5kdc.log
> > > >  admin_server = FILE:/var/log/kadmind.log
> > > >
> > > > [libdefaults]
> > > >  default_realm = TESTRELM.TEST
> > > >  dns_lookup_realm = false
> > > >  dns_lookup_kdc = true
> > >
> > > This ^^^^ sounds wrong on a master
> >
> > no, you need this to find any AD DC in a trusted forest.
>
> Shouldn't SSSD do that for us via proper site discovery ?

yes, this is planned to some extent but you still have a chicken-egg
problem during 'ipa trust-add'.

But see my other email, I think there might be an issue or at least
unexpected behavior with our usage of the admin_server option in
/etc/krb5.conf.

bye,
Sumit
> Simo.
> > bye,
> > Sumit
> > > Simo.
> > >
> > > -- 
> > > Simo Sorce
> > > Sr. Principal Software Engineer
> > > Red Hat, Inc
>
> -- 
> Simo Sorce
> Sr. Principal Software Engineer
> Red Hat, Inc

[Sumit Bose]

On Thu, Sep 21, 2017 at 04:52:32PM +0200, Lukas Slebodnik wrote:
> On (12/09/17 18:44), Sumit Bose wrote:
> > On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> > > ehlo,
> > >
> > > I realized that it might be better to discuss it here rather then in
> > > pull requests because it seems to be related to two different commits.
> > >
> > > I will describe a test case on master with already created replica on another
> > > host.
> > >
> > > kinit as admin
> > >   // create user with dummy password
> > >
> > > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> > >                              --password
> > >
> > > // adding sleep think that first kinit hits slave sometimes and the user is
> > >   // not replicated yet.
> > >
> > > sleep 2
> > >
> > > FirstKinitAs $login $dummypw $password
> > >
> > > FirstKinitAs is a bash function which change initial password
> > > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> > >
> > > Such test works reliably with 1.15.3 and kinit always talk to local master
> > > (I didn't try to remove sleep 2)
> > >
> > > But situation changed a little bit with git master due to following commits
> > > IPA: Only generate kdcinfo files on clients
> > > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
> >
> > Do you have the /etc/krb5.conf available from the host where the test
> > failed. The above patch was written with the assumption that
> > /etc/krb5.conf on the IPA server points to the server itself as
> > ipa-server-install creates it:
> >
> > [realms]
> > IPA.DEVEL = {
> >  kdc = ipa-devel.ipa.devel:88
> >  master_kdc = ipa-devel.ipa.devel:88
> >  admin_server = ipa-devel.ipa.devel:749
> >  default_domain = ipa.devel
> >  pkinit_anchors = FILE:/etc/ipa/ca.crt
> > }
> >
> > Currently I would assume that at least admin_server is missing.
>
> Here you are.
> local master: kvm-02-guest11.testrelm.test
> replica: bkr-hv01-guest19.testrelm.test
>
> [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> includedir /etc/krb5.conf.d/
> includedir /var/lib/sss/pubconf/krb5.include.d/
>
> [logging]
>  default = FILE:/var/log/krb5libs.log
>  kdc = FILE:/var/log/krb5kdc.log
>  admin_server = FILE:/var/log/kadmind.log
>
> [libdefaults]
>  default_realm = TESTRELM.TEST
>  dns_lookup_realm = false
>  dns_lookup_kdc = true
>  rdns = false
>  ticket_lifetime = 24h
>  forwardable = true
>  udp_preference_limit = 0
>  default_ccache_name = KEYRING:persistent:%{uid}
>
> [realms]
>  TESTRELM.TEST = {
>   kdc = kvm-02-guest11.testrelm.test:88
>   master_kdc = kvm-02-guest11.testrelm.test:88
>   admin_server = kvm-02-guest11.testrelm.test:749
>   default_domain = testrelm.test
>   pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
>   pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
> }

Thank you, so the krb5.conf has the expected entries. I did some testing
and found that libkrb5 does a DNS SRV lookup to find the kpasswd server
although the man page says:

"""
       kpasswd_server
              Points to the server where all the password changes are
performed.  If there is no such entry, the port 464 on the admin_server
host will be tried.
"""

To me it looks like the advertised fallback to admin_server if there is
no kpasswd_server defined does not work.

Robbie, is this expected or is it possible that there is an issue in
libkrb5?

bye,
Sumit
> [domain_realm]
>  .testrelm.test = TESTRELM.TEST
>  testrelm.test = TESTRELM.TEST
>  kvm-02-guest11.testrelm.test = TESTRELM.TEST
>
> [dbmodules]
>   TESTRELM.TEST = {
>     db_library = ipadb.so
>   }
>
> [root@kvm-02-guest11 ~]# ls /etc/krb5.conf.d/
> ipa-certauth
> [root@kvm-02-guest11 ~]# cat /etc/krb5.conf.d/ipa-certauth
> [plugins]
>  certauth = {
>   module = ipakdb:kdb/ipadb.so
>   enable_only = ipakdb
>  }
>
> [root@kvm-02-guest11 ~]# ls /var/lib/sss/pubconf/krb5.include.d/
> domain_realm_testrelm_test  krb5_libdefaults  localauth_plugin
> [root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/domain_realm_testrelm_test
> [domain_realm]
> [root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/krb5_libdefaults
> [libdefaults]
>  canonicalize = true
> [root@kvm-02-guest11 ~]# cat /var/lib/sss/pubconf/krb5.include.d/localauth_plugin
> [plugins]
>  localauth = {
>   module = sssd:/usr/lib64/sssd/modules/sssd_krb5_localauth_plugin.so
>  }
> Added user "delegatuser2"
>
> User login: delegatuser2
>   First name: first
>   Last name: last
>   Full name: first last
>   Display name: first last
>   Initials: fl
>   Home directory: /home/delegatuser2
>   GECOS: first last
>   Login shell: /bin/sh
>   Principal name: [e-mail]
>   Principal alias: [e-mail]
>   Email address: [e-mail]
>   UID: 1622800023
>   GID: 1622800023
>   Password: True
>   Member of groups: ipausers
>   Kerberos keys available: True
> :: [   PASS   ] :: add test user account (Expected 0, got 0)
> :: [  BEGIN   ] :: Running 'FirstKinitAs delegatuser2 [e-mail] passw0rd1'
> [3190] 1505997473.156106: Destroying ccache KEYRING:persistent:0:0
> Using default cache: persistent:0:0
> Using principal: [e-mail]
> [3192] 1505997473.161781: Getting initial credentials for [e-mail]
> [3192] 1505997473.163737: Sending request (182 bytes) to TESTRELM.TEST
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.163848: Resolving hostname kvm-02-guest11.testrelm.test
> [3192] 1505997473.164170: Initiating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.164235: Sending TCP request to stream 10.16.68.117:88
> [3192] 1505997473.165916: Received answer (185 bytes) from stream 10.16.68.117:88
> [3192] 1505997473.165924: Terminating TCP connection to stream 10.16.68.117:88
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.165968: Response was from master KDC
> [3192] 1505997473.166001: Received error from KDC: -1765328361/Password has expired
> [3192] 1505997473.166019: Principal expired; getting changepw ticket
> [3192] 1505997473.166025: Getting initial credentials for [e-mail]
> [3192] 1505997473.166040: Setting initial creds service to kadmin/changepw
> [3192] 1505997473.166057: Sending request (177 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.166074: Resolving hostname kvm-02-guest11.testrelm.test
> [3192] 1505997473.166175: Initiating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.166212: Sending TCP request to stream 10.16.68.117:88
> [3192] 1505997473.167923: Received answer (307 bytes) from stream 10.16.68.117:88
> [3192] 1505997473.167930: Terminating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.167956: Received error from KDC: -1765328359/Additional pre-authentication required
> [3192] 1505997473.167975: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
> [3192] 1505997473.167986: Selected etype info: etype aes256-cts, salt "k^pE1RcGTiTV+B^z", params ""
> [3192] 1505997473.167989: Received cookie: MIT
> [3192] 1505997473.168002: PKINIT client has no configured identity; giving up
> [3192] 1505997473.168014: Preauth module pkinit (147) (info) returned: 0/Success
> [3192] 1505997473.168020: PKINIT client has no configured identity; giving up
> [3192] 1505997473.168032: Preauth module pkinit (16) (real) returned: 22/Invalid argument
> [3192] 1505997473.168037: PKINIT client has no configured identity; giving up
> [3192] 1505997473.168041: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> [3192] 1505997473.168046: PKINIT client has no configured identity; giving up
> [3192] 1505997473.168049: Preauth module pkinit (14) (real) returned: 22/Invalid argument
> Password for [e-mail]: 
> [3192] 1505997473.178371: AS key obtained for encrypted timestamp: aes256-cts/B60B
> [3192] 1505997473.178425: Encrypted timestamp (for 1505997473.178262): plain 301AA011180F32303137303932313132333735335AA105020302B856, encrypted 75BDE01CE518AA302EF19F306BFD673D9826B688CDC279D0612EBAC58F427D18B83396D82D26401BF17C982B422B2C990B8E50B96760B4FA
> [3192] 1505997473.178455: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
> [3192] 1505997473.178459: Produced preauth for next request: 133, 2
> [3192] 1505997473.178472: Sending request (272 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.178503: Resolving hostname kvm-02-guest11.testrelm.test
> [3192] 1505997473.178645: Initiating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.178728: Sending TCP request to stream 10.16.68.117:88
> [3192] 1505997473.181321: Received answer (742 bytes) from stream 10.16.68.117:88
> [3192] 1505997473.181330: Terminating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.181369: Processing preauth types: 19
> [3192] 1505997473.181376: Selected etype info: etype aes256-cts, salt "k^pE1RcGTiTV+B^z", params ""
> [3192] 1505997473.181380: Produced preauth for next request: (empty)
> [3192] 1505997473.181386: AS key determined by preauth: aes256-cts/B60B
> [3192] 1505997473.181426: Decrypted AS reply; session key is: aes256-cts/0A8F
> [3192] 1505997473.181440: FAST negotiation: available
> [3192] 1505997473.181489: Attempting password change; 3 tries remaining
> Password expired.  You must change it now.
> Enter new password: 
> Enter it again: 
> [3192] 1505997473.181542: Creating authenticator for [e-mail] -> kadmin/[e-mail], seqnum 0, subkey aes256-cts/4B37, session key aes256-cts/0A8F
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.182186: Resolving hostname bkr-hv01-guest19.testrelm.test.
> [3192] 1505997473.182599: Sending initial UDP request to dgram 2620:52:0:1329:216:3eff:fe27:7207:464
> [3192] 1505997473.220273: Received answer (248 bytes) from dgram 2620:52:0:1329:216:3eff:fe27:7207:464
> [3192] 1505997473.220380: Read AP-REP, time 1505997473.181546, subkey aes256-cts/4B37, seqnum 256549514
> [3192] 1505997473.220416: Getting initial TGT with changed password
> [3192] 1505997473.220423: Getting initial credentials for [e-mail]
> [3192] 1505997473.220468: Sending request (182 bytes) to TESTRELM.TEST (master)
> [sssd_krb5_locator] sssd_krb5_locator_init called
> [sssd_krb5_locator] open failed [/var/lib/sss/pubconf/kdcinfo.TESTRELM.TEST][2][No such file or directory].
> [sssd_krb5_locator] get_krb5info failed.
> [sssd_krb5_locator] sssd_krb5_locator_close called
> [3192] 1505997473.220502: Resolving hostname kvm-02-guest11.testrelm.test
> [3192] 1505997473.220620: Initiating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.220667: Sending TCP request to stream 10.16.68.117:88
> [3192] 1505997473.222921: Received answer (185 bytes) from stream 10.16.68.117:88
> [3192] 1505997473.222930: Terminating TCP connection to stream 10.16.68.117:88
> [3192] 1505997473.222979: Received error from KDC: -1765328361/Password has expired
> kinit: Password has expired while getting initial credentials
> klist: Credentials cache keyring 'persistent:0:0' not found
> :: [ 08:37:53 ] :: ERROR: kinit as delegatuser2 with new password passw0rd1 failed.
> :: [   FAIL   ] :: Command 'FirstKinitAs delegatuser2 [e-mail] passw0rd1' (Expected 0, got 1)

[Robbie Harwood]

Sumit Bose  writes:
> On Thu, Sep 21, 2017 at 04:52:32PM +0200, Lukas Slebodnik wrote:
> > On (12/09/17 18:44), Sumit Bose wrote:
> > > On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> > > > ehlo,
> > > >
> > > > I realized that it might be better to discuss it here rather then in
> > > > pull requests because it seems to be related to two different commits.
> > > >
> > > > I will describe a test case on master with already created replica on another
> > > > host.
> > > >
> > > > kinit as admin
> > > >   // create user with dummy password
> > > >
> > > > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> > > >                              --password
> > > >
> > > > // adding sleep think that first kinit hits slave sometimes and the user is
> > > >   // not replicated yet.
> > > >
> > > > sleep 2
> > > >
> > > > FirstKinitAs $login $dummypw $password
> > > >
> > > > FirstKinitAs is a bash function which change initial password
> > > > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> > > >
> > > > Such test works reliably with 1.15.3 and kinit always talk to local master
> > > > (I didn't try to remove sleep 2)
> > > >
> > > > But situation changed a little bit with git master due to following commits
> > > > IPA: Only generate kdcinfo files on clients
> > > > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
> > >
> > > Do you have the /etc/krb5.conf available from the host where the
> > > test failed. The above patch was written with the assumption that
> > > /etc/krb5.conf on the IPA server points to the server itself as
> > > ipa-server-install creates it:
> > >
> > > [realms]
> > > IPA.DEVEL = {
> > >  kdc = ipa-devel.ipa.devel:88
> > >  master_kdc = ipa-devel.ipa.devel:88
> > >  admin_server = ipa-devel.ipa.devel:749
> > >  default_domain = ipa.devel
> > >  pkinit_anchors = FILE:/etc/ipa/ca.crt
> > > }
> > >
> > > Currently I would assume that at least admin_server is missing.
> >
> > Here you are.
> > local master: kvm-02-guest11.testrelm.test
> > replica: bkr-hv01-guest19.testrelm.test
> >
> > [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> > includedir /etc/krb5.conf.d/
> > includedir /var/lib/sss/pubconf/krb5.include.d/
> >
> > [logging]
> >  default = FILE:/var/log/krb5libs.log
> >  kdc = FILE:/var/log/krb5kdc.log
> >  admin_server = FILE:/var/log/kadmind.log
> >
> > [libdefaults]
> >  default_realm = TESTRELM.TEST
> >  dns_lookup_realm = false
> >  dns_lookup_kdc = true
> >  rdns = false
> >  ticket_lifetime = 24h
> >  forwardable = true
> >  udp_preference_limit = 0
> >  default_ccache_name = KEYRING:persistent:%{uid}
> >
> > [realms]
> >  TESTRELM.TEST = {
> >   kdc = kvm-02-guest11.testrelm.test:88
> >   master_kdc = kvm-02-guest11.testrelm.test:88
> >   admin_server = kvm-02-guest11.testrelm.test:749
> >   default_domain = testrelm.test
> >   pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
> >   pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
> > }
>
> Thank you, so the krb5.conf has the expected entries. I did some testing
> and found that libkrb5 does a DNS SRV lookup to find the kpasswd server
> although the man page says:
>
> """
>        kpasswd_server
>               Points to the server where all the password changes are
> performed.  If there is no such entry, the port 464 on the admin_server
> host will be tried.
> """
>
> To me it looks like the advertised fallback to admin_server if there is
> no kpasswd_server defined does not work.
>
> Robbie, is this expected or is it possible that there is an issue in
> libkrb5?

It's possible there's an issue, but I'd need to look more.  Could you
file a ticket so we can track it?

Thanks,
--Robbie

[Sumit Bose]

On Tue, Oct 03, 2017 at 05:16:24PM -0400, Robbie Harwood wrote:
> Sumit Bose  writes:
> > On Thu, Sep 21, 2017 at 04:52:32PM +0200, Lukas Slebodnik wrote:
> > > On (12/09/17 18:44), Sumit Bose wrote:
> > > > On Tue, Sep 12, 2017 at 03:45:52PM +0200, Lukas Slebodnik wrote:
> > > > > ehlo,
> > > > >
> > > > > I realized that it might be better to discuss it here rather then in
> > > > > pull requests because it seems to be related to two different commits.
> > > > >
> > > > > I will describe a test case on master with already created replica on another
> > > > > host.
> > > > >
> > > > > kinit as admin
> > > > >   // create user with dummy password
> > > > >
> > > > > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> > > > >                              --password
> > > > >
> > > > > // adding sleep think that first kinit hits slave sometimes and the user is
> > > > >   // not replicated yet.
> > > > >
> > > > > sleep 2
> > > > >
> > > > > FirstKinitAs $login $dummypw $password
> > > > >
> > > > > FirstKinitAs is a bash function which change initial password
> > > > > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> > > > >
> > > > > Such test works reliably with 1.15.3 and kinit always talk to local master
> > > > > (I didn't try to remove sleep 2)
> > > > >
> > > > > But situation changed a little bit with git master due to following commits
> > > > > IPA: Only generate kdcinfo files on clients
> > > > > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
> > > >
> > > > Do you have the /etc/krb5.conf available from the host where the
> > > > test failed. The above patch was written with the assumption that
> > > > /etc/krb5.conf on the IPA server points to the server itself as
> > > > ipa-server-install creates it:
> > > >
> > > > [realms]
> > > > IPA.DEVEL = {
> > > >  kdc = ipa-devel.ipa.devel:88
> > > >  master_kdc = ipa-devel.ipa.devel:88
> > > >  admin_server = ipa-devel.ipa.devel:749
> > > >  default_domain = ipa.devel
> > > >  pkinit_anchors = FILE:/etc/ipa/ca.crt
> > > > }
> > > >
> > > > Currently I would assume that at least admin_server is missing.
> > >
> > > Here you are.
> > > local master: kvm-02-guest11.testrelm.test
> > > replica: bkr-hv01-guest19.testrelm.test
> > >
> > > [root@kvm-02-guest11 ~]# cat /etc/krb5.conf
> > > includedir /etc/krb5.conf.d/
> > > includedir /var/lib/sss/pubconf/krb5.include.d/
> > >
> > > [logging]
> > >  default = FILE:/var/log/krb5libs.log
> > >  kdc = FILE:/var/log/krb5kdc.log
> > >  admin_server = FILE:/var/log/kadmind.log
> > >
> > > [libdefaults]
> > >  default_realm = TESTRELM.TEST
> > >  dns_lookup_realm = false
> > >  dns_lookup_kdc = true
> > >  rdns = false
> > >  ticket_lifetime = 24h
> > >  forwardable = true
> > >  udp_preference_limit = 0
> > >  default_ccache_name = KEYRING:persistent:%{uid}
> > >
> > > [realms]
> > >  TESTRELM.TEST = {
> > >   kdc = kvm-02-guest11.testrelm.test:88
> > >   master_kdc = kvm-02-guest11.testrelm.test:88
> > >   admin_server = kvm-02-guest11.testrelm.test:749
> > >   default_domain = testrelm.test
> > >   pkinit_anchors = FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem
> > >   pkinit_pool = FILE:/var/lib/ipa-client/pki/ca-bundle.pem
> > > }
> >
> > Thank you, so the krb5.conf has the expected entries. I did some testing
> > and found that libkrb5 does a DNS SRV lookup to find the kpasswd server
> > although the man page says:
> >
> > """
> >        kpasswd_server
> >               Points to the server where all the password changes are
> > performed.  If there is no such entry, the port 464 on the admin_server
> > host will be tried.
> > """
> >
> > To me it looks like the advertised fallback to admin_server if there is
> > no kpasswd_server defined does not work.
> >
> > Robbie, is this expected or is it possible that there is an issue in
> > libkrb5?
>
> It's possible there's an issue, but I'd need to look more.  Could you
> file a ticket so we can track it?

Thank you, I opened https://bugzilla.redhat.com/show_bug.cgi?id=1498347.

bye,
Sumit
> Thanks,
> --Robbie

[Lukas Slebodnik]

On (12/09/17 15:45), Lukas Slebodnik wrote:
> ehlo,
>
> I realized that it might be better to discuss it here rather then in
> pull requests because it seems to be related to two different commits.
>
> I will describe a test case on master with already created replica on another
> host.
>
> kinit as admin
>  // create user with dummy password
>
> echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
>                             --password
>
> // adding sleep think that first kinit hits slave sometimes and the user is
>  // not replicated yet.
>
> sleep 2
>
> FirstKinitAs $login $dummypw $password
>
> FirstKinitAs is a bash function which change initial password
> something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
>
> Such test works reliably with 1.15.3 and kinit always talk to local master
> (I didn't try to remove sleep 2)
>
> But situation changed a little bit with git master due to following commits
> IPA: Only generate kdcinfo files on clients
> https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6

Jakub,
Could you explain what was the purpose of the patch?
Because I do not think that patch fix anything.

If there were some issues with generated kdcinfo files on ipa replicas
then I assume it is a bug in replica promotion which left _srv_ in
ipa_server

https://pagure.io/freeipa/issue/7127
https://github.com/freeipa/freeipa/pull/1005

Because my experience is that after reverting patch
a309525cc47da726461aec1f238165c17aade2a6 sssd generate kdcinfo
just for local kdc server and sssd_krb5_locator_plugin.so will
use it and do not allow krb5 libs to try srv discovery.

I might be wrong or I could miss something and there might be
something else fishy in ipa*-install.

LS

[Jakub Hrozek]

On Thu, Sep 21, 2017 at 01:15:00PM +0200, Lukas Slebodnik wrote:
> On (12/09/17 15:45), Lukas Slebodnik wrote:
> > ehlo,
> >
> > I realized that it might be better to discuss it here rather then in
> > pull requests because it seems to be related to two different commits.
> >
> > I will describe a test case on master with already created replica on another
> > host.
> >
> > kinit as admin
> >  // create user with dummy password
> >
> > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> >                             --password
> >
> > // adding sleep think that first kinit hits slave sometimes and the user is
> >  // not replicated yet.
> >
> > sleep 2
> >
> > FirstKinitAs $login $dummypw $password
> >
> > FirstKinitAs is a bash function which change initial password
> > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> >
> > Such test works reliably with 1.15.3 and kinit always talk to local master
> > (I didn't try to remove sleep 2)
> >
> > But situation changed a little bit with git master due to following commits
> > IPA: Only generate kdcinfo files on clients
> > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
>
> Jakub,
> Could you explain what was the purpose of the patch?

Protect against generating kdcinfo files that contain a different
address than the IPA master we are running at. The bug itself is just
additional protection from sssd messing up a valid krb5.conf
configuration.
> Because I do not think that patch fix anything.
>
> If there were some issues with generated kdcinfo files on ipa replicas
> then I assume it is a bug in replica promotion which left _srv_ in
> ipa_server

Yes, but even if that bug is fixed, it is pointless to generate the
files, because the only address that will ever make sense is the IPA
server. And it should be already defined in krb5.conf.
> https://pagure.io/freeipa/issue/7127
> https://github.com/freeipa/freeipa/pull/1005
>
> Because my experience is that after reverting patch
> a309525cc47da726461aec1f238165c17aade2a6 sssd generate kdcinfo
> just for local kdc server and sssd_krb5_locator_plugin.so will
> use it and do not allow krb5 libs to try srv discovery.

Yes, but you don't want to allow SRV discovery on the masters. Only on
clients. But I thought krb5.conf should also contain only the local
master..does the config file in the issue you saw contain something
else?

I mean, if we revert the patch and krb5.conf contains no records or multiple
records, then I think the libkrb5 configuration is broken and we are relying
on sssd injecting a valid value into an otherwise invalid krb5 configuration.
> I might be wrong or I could miss something and there might be
> something else fishy in ipa*-install.
>
> LS
> _______________________________________________
> sssd-devel mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]

[Lukas Slebodnik]

On (21/09/17 13:22), Jakub Hrozek wrote:
> On Thu, Sep 21, 2017 at 01:15:00PM +0200, Lukas Slebodnik wrote:
> > On (12/09/17 15:45), Lukas Slebodnik wrote:
> > > ehlo,
> > >
> > > I realized that it might be better to discuss it here rather then in
> > > pull requests because it seems to be related to two different commits.
> > >
> > > I will describe a test case on master with already created replica on another
> > > host.
> > >
> > > kinit as admin
> > >  // create user with dummy password
> > >
> > > echo $dummypw | ipa user-add $login --first "$firstname" --last "$lastname" \
> > >                             --password
> > >
> > > // adding sleep think that first kinit hits slave sometimes and the user is
> > >  // not replicated yet.
> > >
> > > sleep 2
> > >
> > > FirstKinitAs $login $dummypw $password
> > >
> > > FirstKinitAs is a bash function which change initial password
> > > something like: echo -e "$password\n$newpassword\n$newpassword" | kinit -V $username
> > >
> > > Such test works reliably with 1.15.3 and kinit always talk to local master
> > > (I didn't try to remove sleep 2)
> > >
> > > But situation changed a little bit with git master due to following commits
> > > IPA: Only generate kdcinfo files on clients
> > > https://pagure.io/SSSD/sssd/c/a309525cc47da726461aec1f238165c17aade2a6
> >
> > Jakub,
> > Could you explain what was the purpose of the patch?
>
> Protect against generating kdcinfo files that contain a different
> address than the IPA master we are running at. The bug itself is just
> additional protection from sssd messing up a valid krb5.conf
> configuration.
> > Because I do not think that patch fix anything.
> >
> > If there were some issues with generated kdcinfo files on ipa replicas
> > then I assume it is a bug in replica promotion which left _srv_ in
> > ipa_server
>
> Yes, but even if that bug is fixed, it is pointless to generate the
> files, because the only address that will ever make sense is the IPA
> server. And it should be already defined in krb5.conf.
> > https://pagure.io/freeipa/issue/7127
> > https://github.com/freeipa/freeipa/pull/1005
> >
> > Because my experience is that after reverting patch
> > a309525cc47da726461aec1f238165c17aade2a6 sssd generate kdcinfo
> > just for local kdc server and sssd_krb5_locator_plugin.so will
> > use it and do not allow krb5 libs to try srv discovery.
>
> Yes, but you don't want to allow SRV discovery on the masters. Only on
> clients. But I thought krb5.conf should also contain only the local
> master..does the config file in the issue you saw contain something
> else?
>
> I mean, if we revert the patch and krb5.conf contains no records or multiple
> records, then I think the libkrb5 configuration is broken and we are relying
> on sssd injecting a valid value into an otherwise invalid krb5 configuration.

I'm waiting for machine to see content of krb5.conf and then I'll check
Sumit's assumption.

LS

[Jakub Hrozek]

On Thu, Sep 21, 2017 at 01:30:17PM +0200, Lukas Slebodnik wrote:
> On (21/09/17 13:22), Jakub Hrozek wrote:
> > clients. But I thought krb5.conf should also contain only the local
> > master..does the config file in the issue you saw contain something
> > else?
> >
> > I mean, if we revert the patch and krb5.conf contains no records or multiple
> > records, then I think the libkrb5 configuration is broken and we are relying
> > on sssd injecting a valid value into an otherwise invalid krb5 configuration.
>
> I'm waiting for machine to see content of krb5.conf and then I'll check
> Sumit's assumption.

I also wonder if the bug might be in IPv4/IPv6 resolution. Because IIRC
libc prefers IPv6 addresses during resulution, but SSSD prefers IPv4 and
the kdcinfo file would contain a v4 address.

But then I guess reverting the patch and injecting the kdcinfo file
would help..

[Lukas Slebodnik]

On (21/09/17 13:33), Jakub Hrozek wrote:
> On Thu, Sep 21, 2017 at 01:30:17PM +0200, Lukas Slebodnik wrote:
> > On (21/09/17 13:22), Jakub Hrozek wrote:
> > > clients. But I thought krb5.conf should also contain only the local
> > > master..does the config file in the issue you saw contain something
> > > else?
> > >
> > > I mean, if we revert the patch and krb5.conf contains no records or multiple
> > > records, then I think the libkrb5 configuration is broken and we are relying
> > > on sssd injecting a valid value into an otherwise invalid krb5 configuration.
> >
> > I'm waiting for machine to see content of krb5.conf and then I'll check
> > Sumit's assumption.
>
> I also wonder if the bug might be in IPv4/IPv6 resolution. Because IIRC
> libc prefers IPv6 addresses during resulution, but SSSD prefers IPv4 and
> the kdcinfo file would contain a v4 address.
>
> But then I guess reverting the patch and injecting the kdcinfo file
> would help..

If it's a bug in krb5-libs then we should fix it (because it can cause
intermittent failures in other tests);
* reverting the patch might be a temporary workaround.

LS