#4053 Cannot update password with krb5
Closed: Invalid by sveyret. Opened by sveyret.

Hi all,

I am trying to build a personal network and currently making tests on VMs. I would like users to be identified using Kerberos over LDAP.

On the client computer, using sssd, password update (both from login and passwd) is failing (and then preventing to login if principal is built with +needchange). It asks for previous password, but does not ask for new one. With passwd command, it gives an “Authentication token manipulation error”.

I can update the password when logging to the server (server is using pam_krb5.so and not sssd) and also using kinit, even from the client.

Because I made many tests with different realms and server names, it may be a matter of cache, because I am almost sure it worked once, but I deleted all /var/lib/sss and reinstalled sssd on the client.

Both server and client are running Gentoo.

Here is the definition of a user in LDAP:

dn: uid=stephane,ou=User,ou=People,dc=mynetwork,dc=org
objectclass: inetOrgPerson
objectclass: posixAccount
objectclass: shadowAccount
cn: stephane.veyret
uid: stephane
uidNumber: 1000
gidNumber: 1001
gecos: stephane
givenName: Stéphane
sn: Veyret
displayName: Stéphane Veyret
jpegPhoto:< file:////root/photos/stephane.jpg
homedirectory: /home/stephane
loginshell: /bin/bash
preferredLanguage: fr

Here is how principal is created for this user:

kadmin.local add_principal \
-x dn="uid=stephane,ou=User,ou=People,dc=mynetwork,dc=org" \
+requires_preauth \
+needchange \
stephane

But configuration of serveur seems to be OK, as I can update the password using kinit.

On the client side, here is sssd.conf:

[sssd]
config_file_version = 2
services = nss, pam
domains = MYNETWORK.ORG
[nss]
[pam]
offline_failed_login_attempts = 3
[domain/MYNETWORK.ORG]
id_provider = ldap
ldap_uri = ldaps://server.int.mynetwork.org
ldap_search_base = dc=mynetwork,dc=org
ldap_user_search_base = ou=User,ou=People,dc=mynetwork,dc=org
ldap_group_search_base = ou=Group,dc=mynetwork,dc=org
auth_provider = krb5
chpass_provider = krb5
krb5_server = pordo.int.mynetwork.org
krb5_realm = MYNETWORK.ORG
krb5_store_password_if_offline = true
cache_credentials = true

and pam.d/system-auth:

auth        required      pam_env.so
auth        sufficient    pam_unix.so try_first_pass nullok
auth        sufficient    pam_sss.so use_first_pass
auth        required      pam_deny.so
account     required      pam_unix.so
account     [default=bad success=ok user_unknown=ignore] pam_sss.so
account     optional      pam_permit.so
password    sufficient    pam_unix.so try_first_pass use_authtok sha512 shadow
password    sufficient    pam_sss.so use_first_pass use_authtok
password    required      pam_deny.so
session     required      pam_limits.so
session     required      pam_env.so
session     optional      pam_mkhomedir.so skel=/etc/skel umask=0077
session     required      pam_unix.so
session     optional      pam_sss.so
session     optional      pam_permit.so

During a password modification attempt, here is the auth.log on the server:

Aug  5 16:48:02 server krb5kdc[3008]: AS_REQ (1 etypes {18}) 10.112.2.1: NEEDED_PREAUTH: stephane@MYNETWORK.ORG for kadmin/changepw@MYNETWORK.ORG, Additional pre-authentication required
Aug  5 16:48:02 server krb5kdc[3008]: AS_REQ (1 etypes {18}) 10.112.2.1: ISSUE: authtime 1565016482, etypes {rep=18 tkt=18 ses=18}, stephane@MYNETWORK.ORG for kadmin/changepw@MYNETWORK.ORG
Aug  5 16:48:02 server krb5kdc[3008]: AS_REQ (1 etypes {18}) 10.112.2.1: NEEDED_PREAUTH: stephane@MYNETWORK.ORG for kadmin/changepw@MYNETWORK.ORG, Additional pre-authentication required
Aug  5 16:48:02 server krb5kdc[3008]: AS_REQ (1 etypes {18}) 10.112.2.1: ISSUE: authtime 1565016482, etypes {rep=18 tkt=18 ses=18}, stephane@MYNETWORK.ORG for kadmin/changepw@MYNETWORK.ORG

… and (extract of) syslog:

Aug  5 16:48:02 server slapd[2974]: conn=1002 op=173 SRCH base="ou=User,ou=People,dc=mynetwork,dc=org" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/MYNETWORK.ORG@MYNETWORK.ORG))" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=173 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbPrincipalAuthInd krbExtraData krbObjectReferences krbAllowedToDelegateTo krbPwdHistory 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=173 SEARCH RESULT tag=101 err=0 nentries=0 text= 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=174 SRCH base="cn=MYNETWORK.ORG,cn=krbcontainer,dc=mynetwork,dc=org" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/MYNETWORK.ORG@MYNETWORK.ORG))" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=174 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbPrincipalAuthInd krbExtraData krbObjectReferences krbAllowedToDelegateTo krbPwdHistory 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=174 ENTRY dn="krbPrincipalName=krbtgt/MYNETWORK.ORG@MYNETWORK.ORG,cn=mynetwork.org,cn=krbcontainer,dc=mynetwork,dc=org" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=174 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=175 SRCH base="cn=default,cn=MYNETWORK.ORG,cn=krbcontainer,dc=mynetwork,dc=org" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=175 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=175 ENTRY dn="cn=default,cn=mynetwork.org,cn=krbcontainer,dc=mynetwork,dc=org" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=175 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=176 SRCH base="cn=default,cn=MYNETWORK.ORG,cn=krbcontainer,dc=mynetwork,dc=org" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=176 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=176 ENTRY dn="cn=default,cn=mynetwork.org,cn=krbcontainer,dc=mynetwork,dc=org" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=176 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=177 SRCH base="uid=stephane,ou=User,ou=People,dc=mynetwork,dc=org" scope=0 deref=0 filter="(objectClass=*)" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=177 SRCH attr=objectclass 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=177 ENTRY dn="uid=stephane,ou=user,ou=people,dc=mynetwork,dc=org" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=177 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=178 MOD dn="uid=stephane,ou=User,ou=People,dc=mynetwork,dc=org" 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=178 MOD attr=krbLastSuccessfulAuth krbExtraData 
Aug  5 16:48:02 server slapd[2974]: conn=1002 op=178 RESULT tag=103 err=0 text=

Here is (an extract of) the output of sssd during password change for initial authentication:

(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [main] (0x0400): krb5_child started.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [unpack_buffer] (0x1000): total buffer size: [160]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [unpack_buffer] (0x0100): cmd [247] uid [1003] gid [1001] validate [false] enterprise principal [false] offline [false] UPN [stephane@MYNETWORK.ORG]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1003_XXXXXX] old_ccname: [FILE:/tmp/krb5cc_1003_a22XYi] keytab: [/etc/krb5.keytab]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [check_use_fast] (0x0100): Not using FAST.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [switch_creds] (0x0200): Switch user to [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [switch_creds] (0x0200): Switch user to [0][0].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1003_a22XYi] and is  active and TGT is  valid.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [become_user] (0x0200): Trying to become user [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [main] (0x2000): Running as [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [become_user] (0x0200): Trying to become user [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [become_user] (0x0200): Already user [1003].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [k5c_setup] (0x2000): Running as [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [set_lifetime_options] (0x0100): No specific lifetime requested.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [false]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [main] (0x0400): Will perform password change checks
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [changepw_child] (0x1000): Password change operation
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [changepw_child] (0x0400): Attempting kinit for realm [MYNETWORK.ORG]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200289: Getting initial credentials for stephane@MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200290: Setting initial creds service to kadmin/changepw
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200292: Sending unauthenticated request
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200293: Sending request (146 bytes) to MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200294: Sending initial UDP request to dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200295: Received answer (233 bytes) from dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200296: Response was from master KDC
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200297: Received error from KDC: -1765328359/Additional pre-authentication required
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200300: Preauthenticating using KDC method data
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200301: Processing preauth types: 136, 19, 2, 133
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200302: Selected etype info: etype aes256-cts, salt "MYNETWORK.ORGstephane", params ""
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200303: Received cookie: MIT
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_krb5_responder] (0x4000): Got question [password].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200304: AS key obtained for encrypted timestamp: aes256-cts/8BD8
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200306: Encrypted timestamp (for 1565018936.84846): plain 301AA011180F32303139303830353135323835365AA1050203014B6E, encrypted 7BC3B05A7BFE3243C00077791D34484485DE258608D3B2E9CA10005409AD71F9F4FD3FE0DB64AEE279422F9324CAC8AD3198F94E4A820351
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200307: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200308: Produced preauth for next request: 133, 2
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200309: Sending request (239 bytes) to MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200310: Sending initial UDP request to dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200311: Received answer (704 bytes) from dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200312: Response was from master KDC
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200313: Processing preauth types: 19
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200314: Selected etype info: etype aes256-cts, salt "MYNETWORK.ORGstephane", params ""
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200315: Produced preauth for next request: (empty)
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200316: AS key determined by preauth: aes256-cts/8BD8
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200317: Decrypted AS reply; session key is: aes256-cts/E603
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [sss_child_krb5_trace_cb] (0x4000): [5367] 1565018935.200318: FAST negotiation: available
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [changepw_child] (0x2000): chpass is not using OTP
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [changepw_child] (0x1000): Initial authentication for change password operation successful.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [k5c_send_data] (0x0200): Received error code 0
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [pack_response_packet] (0x2000): response packet size: [4]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [k5c_send_data] (0x4000): Response sent.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5367]]]] [main] (0x0400): krb5_child completed successfully

…and for password change:

(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [main] (0x0400): krb5_child started.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [unpack_buffer] (0x1000): total buffer size: [168]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [unpack_buffer] (0x0100): cmd [246] uid [1003] gid [1001] validate [false] enterprise principal [false] offline [false] UPN [stephane@MYNETWORK.ORG]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1003_XXXXXX] old_ccname: [FILE:/tmp/krb5cc_1003_a22XYi] keytab: [/etc/krb5.keytab]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [check_use_fast] (0x0100): Not using FAST.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [switch_creds] (0x0200): Switch user to [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [switch_creds] (0x0200): Switch user to [0][0].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1003_a22XYi] and is  active and TGT is  valid.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [become_user] (0x0200): Trying to become user [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [main] (0x2000): Running as [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [become_user] (0x0200): Trying to become user [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [become_user] (0x0200): Already user [1003].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [k5c_setup] (0x2000): Running as [1003][1001].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [set_lifetime_options] (0x0100): No specific lifetime requested.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [false]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [main] (0x0400): Will perform password change
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [changepw_child] (0x1000): Password change operation
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [changepw_child] (0x0400): Attempting kinit for realm [MYNETWORK.ORG]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350545: Getting initial credentials for stephane@MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350546: Setting initial creds service to kadmin/changepw
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350548: Sending unauthenticated request
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350549: Sending request (146 bytes) to MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350550: Sending initial UDP request to dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350551: Received answer (233 bytes) from dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350552: Response was from master KDC
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350553: Received error from KDC: -1765328359/Additional pre-authentication required
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350556: Preauthenticating using KDC method data
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350557: Processing preauth types: 136, 19, 2, 133
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350558: Selected etype info: etype aes256-cts, salt "MYNETWORK.ORGstephane", params ""
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350559: Received cookie: MIT
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_krb5_responder] (0x4000): Got question [password].
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350560: AS key obtained for encrypted timestamp: aes256-cts/8BD8
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350562: Encrypted timestamp (for 1565018936.84849): plain 301AA011180F32303139303830353135323835365AA1050203014B71, encrypted D63D5CCF3D5981615370FD01D3177D9F48B6E879D62653F5026F04B6AFB8EDE55BEEC54F84EC9ED5BBB07292787E95528A801ADC1B722FA1
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350563: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350564: Produced preauth for next request: 133, 2
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350565: Sending request (239 bytes) to MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350566: Sending initial UDP request to dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350567: Received answer (704 bytes) from dgram 10.112.0.1:88
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350568: Response was from master KDC
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350569: Processing preauth types: 19
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350570: Selected etype info: etype aes256-cts, salt "MYNETWORK.ORGstephane", params ""
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350571: Produced preauth for next request: (empty)
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350572: AS key determined by preauth: aes256-cts/8BD8
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350573: Decrypted AS reply; session key is: aes256-cts/513B
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [sss_child_krb5_trace_cb] (0x4000): [5368] 1565018935.350574: FAST negotiation: available
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [changepw_child] (0x2000): chpass is not using OTP
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [changepw_child] (0x0020): Failed to fetch new password [2] No such file or directory.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [k5c_send_data] (0x0200): Received error code 1432158218
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [pack_response_packet] (0x2000): response packet size: [4]
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [k5c_send_data] (0x4000): Response sent.
(Mon Aug  5 17:28:55 2019) [[sssd[krb5_child[5368]]]] [main] (0x0400): krb5_child completed successfully

I tried a lot of things but now have no more idea of what could make it fail. If someone can give me a clue, that'd be great.


Hi,

it looks like the krb5_child process does not know about the new password. Can you attache the related parts from sssd_pam.log and sssd_your.domain.log with debug_level=9 as well to see where this information might got lost?

bye,
Sumit

Thank you @sbose for your response. That's also what the “Failed to fetch new password” made me think. But actually, it cannot have a new password, because it does not ask for it. Is this a problem of pam configuration?

Here are logs before the password change part:

(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_cmd_chauthtok] (0x0100): entering pam_cmd_chauthtok
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'stephane' matched without domain, user is stephane
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CHAUTHTOK
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): user: stephane
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): service: passwd
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): tty: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): priv: 0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 5366
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): logon name: stephane
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_initgr_check_timeout] (0x2000): User [stephane] found in PAM cache.
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_set_plugin] (0x2000): CR #8: Setting "Initgroups by name" plugin
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_send] (0x0400): CR #8: New request 'Initgroups by name'
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_process_input] (0x0400): CR #8: Parsing input name [stephane]
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'stephane' matched without domain, user is stephane
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_set_name] (0x0400): CR #8: Setting name [stephane]
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #8: Performing a multi-domain search
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #8: Search will check the cache and check the data provider
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [child_sig_handler] (0x1000): Waiting for child [5367].
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [child_sig_handler] (0x0100): child [5367] finished successfully.
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain MYNETWORK.ORG type POSIX is valid
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #8: Using domain [MYNETWORK.ORG]
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #8: Preparing input data for domain [MYNETWORK.ORG] rules
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_send] (0x0400): CR #8: Looking up stephane@mynetwork.org
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #8: Checking negative cache for [stephane@mynetwork.org]
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/MYNETWORK.ORG/stephane@mynetwork.org]
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #8: [stephane@mynetwork.org] is not present in negative cache
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #8: Looking up [stephane@mynetwork.org] in cache
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x557ef88eb3b0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x557ef8909ce0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Running timer event 0x557ef88eb3b0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef8909ce0 "ltdb_timeout"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef88eb3b0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x557ef88eb3b0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x557ef8909ce0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Running timer event 0x557ef88eb3b0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef8909ce0 "ltdb_timeout"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef88eb3b0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x557ef89097f0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x557ef88fbca0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Running timer event 0x557ef89097f0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef88fbca0 "ltdb_timeout"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x557ef89097f0 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_send] (0x0400): CR #8: Returning [stephane@mynetwork.org] from cache
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #8: This request type does not support filtering result by negative cache
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #8: Found 1 entries in domain MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [cache_req_done] (0x0400): CR #8: Finished: Success
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is stephane@mynetwork.org
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [stephane] added to PAM initgroup cache
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CHAUTHTOK
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): domain: MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): user: stephane@mynetwork.org
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): service: passwd
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): tty: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): priv: 0
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 5366
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_print_data] (0x0100): logon name: stephane
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x557ef88e3de0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sbus_dispatch] (0x4000): dbus conn: 0x55f3623c43d0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sbus_dispatch] (0x4000): Dispatching.
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on path /org/freedesktop/sssd/dataprovider
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [dp_pam_handler] (0x0100): Got request with the following data
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): command: SSS_PAM_CHAUTHTOK
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): domain: MYNETWORK.ORG
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): user: stephane@mynetwork.org
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): service: passwd
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): tty: 
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): ruser: 
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): rhost: 
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): authtok type: 1
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): newauthtok type: 0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): priv: 0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): cli_pid: 5366
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [pam_print_data] (0x0100): logon name: not set
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [dp_attach_req] (0x0400): DP Request [PAM Chpass 2nd #12]: New request. Flags [0000].
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sss_domain_get_state] (0x1000): Domain MYNETWORK.ORG is Active
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [stephane@mynetwork.org] is empty, running request [0x55f3623ccad0] immediately.
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [krb5_setup] (0x4000): No mapping for: stephane@mynetwork.org
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3623d2d00
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3624b5bc0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Running timer event 0x55f3623d2d00 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Destroying timer event 0x55f3624b5bc0 "ltdb_timeout"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Destroying timer event 0x55f3623d2d00 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3623d2d00
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3624b5bc0
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Running timer event 0x55f3623d2d00 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Destroying timer event 0x55f3624b5bc0 "ltdb_timeout"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [ldb] (0x4000): Destroying timer event 0x55f3623d2d00 "ltdb_callback"
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [check_ccache_re] (0x1000): Ccache directory name [/tmp] does not contain illegal patterns.
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [check_ccache_re] (0x1000): Ccache directory name [FILE:/tmp/krb5cc_1003_XXXXXX] does not contain illegal patterns.
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'KERBEROS'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [get_server_status] (0x1000): Status of server 'pordo.int.mynetwork.org' is 'working'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [get_port_status] (0x1000): Port status of port 0 for server 'pordo.int.mynetwork.org' is 'working'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [get_server_status] (0x1000): Status of server 'pordo.int.mynetwork.org' is 'working'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [be_resolve_server_process] (0x0200): Found address for server pordo.int.mynetwork.org: [10.112.0.1] TTL 1200
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'KPASSWD'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [get_server_status] (0x1000): Status of server 'pordo.int.mynetwork.org' is 'working'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [get_server_status] (0x1000): Status of server 'pordo.int.mynetwork.org' is 'working'
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [be_resolve_server_process] (0x0200): Found address for server pordo.int.mynetwork.org: [10.112.0.1] TTL 1200
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [sss_domain_get_state] (0x1000): Domain MYNETWORK.ORG is Active
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5368]
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5368]
(Mon Aug  5 17:28:55 2019) [sssd[be[MYNETWORK.ORG]]] [write_pipe_handler] (0x0400): All data has been sent!
(Mon Aug  5 17:28:55 2019) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0

Thank you @sbose, you put me on the good path. It actually was a problem of pam configuration: I cannot use use_authtok in this case. I will close the issue.

Metadata Update from @sveyret:
- Issue close_status updated to: Invalid
- Issue status updated to: Closed (was: Open)

Thank you @sbose, you put me on the good path. It actually was a problem of pam configuration: I cannot use use_authtok in this case. I will close the issue.

yw. Yes use_authtok cannot be used since it is not available. In Fedora/RHEL there is typically pam_pwquality.so or similar pam modules which will ask for the new password and check for local users if the new password if sufficiently complex. In this case use_authtokshould be used.

bye,
Sumit

SSSD is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in SSSD's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/SSSD/sssd/issues/5021

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata