Hello Alexander.
I tried to reproduce the error with standard command ipa passwd and kpasswd in a shell.
I was not able to reproduce the problem (even by using the same passwords).
I also performed another test in python.
I added a loop to retry the kpasswd if it fails with this kind of errors.
If the kpasswd fails with this error, I also added an ipa user-unlock to prevent the user to be locked.
For the ipa user-unlock, I also uses the ipa python library.
It works at the fourth iteration, but the three first times, it fails with the error I mentioned before.
Here is the logs I wrote about that :
(don't worry about the credentials, this is a test user that I removed just after my command)
###
2018-07-03 17:12:36,235;INFO;BEGIN
2018-07-03 17:12:36,235;INFO;Creating user login test_user
2018-07-03 17:12:36,235;INFO;Creating IPA account...
2018-07-03 17:12:45,127;INFO;Generating and setting password for the login test_user...
2018-07-03 17:12:45,276;INFO;ipa passwd for user test_user has ended with the following summary : Changed password for "test_user@MYREALM"
2018-07-03 17:12:45,280;INFO;login = test_user, one_time_password = Kk)4YIRq, password = fJ6f4%(5
2018-07-03 17:12:45,503;INFO;1st kpasswd try
2018-07-03 17:12:45,503;INFO;kpasswd stdout : [47695] 1530630765.283620: Getting initial credentials for test_user@MYREALM
[47695] 1530630765.283766: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47695] 1530630765.283812: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47695] 1530630765.283818: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47695] 1530630765.283821: Using FAST due to armor ccache negotiation result
[47695] 1530630765.283831: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47695] 1530630765.283862: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47695] 1530630765.283882: Armor ccache sesion key: aes256-cts/2559
[47695] 1530630765.283914: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/2FB3, session key aes256-cts/2559
[47695] 1530630765.284000: FAST armor key: aes256-cts/552F
[47695] 1530630765.284013: Setting initial creds service to kadmin/changepw
[47695] 1530630765.284018: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47695] 1530630765.284043: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47695] 1530630765.284046: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47695] 1530630765.284048: Using FAST due to armor ccache negotiation result
[47695] 1530630765.284055: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47695] 1530630765.284076: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47695] 1530630765.284082: Armor ccache sesion key: aes256-cts/2559
[47695] 1530630765.284094: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/7296, session key aes256-cts/2559
[47695] 1530630765.284126: FAST armor key: aes256-cts/1070
[47695] 1530630765.284139: Encoding request body and padata into FAST request
[47695] 1530630765.284176: Sending request (1019 bytes) to MYREALM
[47695] 1530630765.284263: Resolving hostname ipamasterhostname
[47695] 1530630765.284544: Initiating TCP connection to stream ipamasterIP:88
[47695] 1530630765.284711: Sending TCP request to stream ipamasterIP:88
[47695] 1530630765.468306: Received answer from stream ipamasterIP:88
[47695] 1530630765.468362: Response was from master KDC
[47695] 1530630765.468390: Received error from KDC: -1765328359/Additional pre-authentication required
[47695] 1530630765.468402: Decoding FAST response
[47695] 1530630765.468470: Processing preauth types: 136, 19, 138, 133, 137
[47695] 1530630765.468478: Received cookie: MIT
Password for test_user@MYREALM: [47695] 1530630765.476399: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
[47695] 1530630765.476404: Produced preauth for next request: 133, 138
[47695] 1530630765.476407: Encoding request body and padata into FAST request
[47695] 1530630765.476470: Sending request (1118 bytes) to MYREALM
[47695] 1530630765.476489: Resolving hostname ipamasterhostname
[47695] 1530630765.476657: Initiating TCP connection to stream ipamasterIP:88
[47695] 1530630765.476763: Sending TCP request to stream ipamasterIP:88
[47695] 1530630765.503131: Received answer from stream ipamasterIP:88
[47695] 1530630765.503185: Response was from master KDC
[47695] 1530630765.503212: Received error from KDC: -1765328360/Preauthentication failed
[47695] 1530630765.503216: Decoding FAST response
[47695] 1530630765.503265: Preauth tryagain input types: 136, 19, 138, 133, 137
kpasswd: Preauthentication failed getting initial ticket
)
2018-07-03 17:12:45,504;INFO;sortie err cmd : None)
2018-07-03 17:12:45,607;INFO;Action 'user-unlock' for user test_user ended with the following summary : Unlocked account " test_user"
2018-07-03 17:12:45,608;INFO;login = test_user, one_time_password = Kk)4YIRq, password = fJ6f4%(5
2018-07-03 17:12:45,503;INFO;2nd kpasswd try
2018-07-03 17:12:45,756;INFO;kpasswd stdout : [47700] 1530630765.610794: Getting initial credentials for test_user@MYREALM
[47700] 1530630765.610945: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47700] 1530630765.610998: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47700] 1530630765.611003: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47700] 1530630765.611006: Using FAST due to armor ccache negotiation result
[47700] 1530630765.611016: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47700] 1530630765.611044: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47700] 1530630765.611061: Armor ccache sesion key: aes256-cts/2559
[47700] 1530630765.611089: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/7F39, session key aes256-cts/2559
[47700] 1530630765.611168: FAST armor key: aes256-cts/79AB
[47700] 1530630765.611179: Setting initial creds service to kadmin/changepw
[47700] 1530630765.611184: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47700] 1530630765.611208: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47700] 1530630765.611212: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47700] 1530630765.611213: Using FAST due to armor ccache negotiation result
[47700] 1530630765.611219: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47700] 1530630765.611240: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47700] 1530630765.611245: Armor ccache sesion key: aes256-cts/2559
[47700] 1530630765.611256: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/2BFD, session key aes256-cts/2559
[47700] 1530630765.611288: FAST armor key: aes256-cts/62C4
[47700] 1530630765.611299: Encoding request body and padata into FAST request
[47700] 1530630765.611333: Sending request (1019 bytes) to MYREALM
[47700] 1530630765.611418: Resolving hostname ipamasterhostname
[47700] 1530630765.611608: Initiating TCP connection to stream ipamasterIP:88
[47700] 1530630765.611769: Sending TCP request to stream ipamasterIP:88
[47700] 1530630765.675154: Received answer from stream ipamasterIP:88
[47700] 1530630765.675208: Response was from master KDC
[47700] 1530630765.675238: Received error from KDC: -1765328359/Additional pre-authentication required
[47700] 1530630765.675249: Decoding FAST response
[47700] 1530630765.675311: Processing preauth types: 136, 19, 138, 133, 137
[47700] 1530630765.675319: Received cookie: MIT
Password for test_user@MYREALM: [47700] 1530630765.682884: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
[47700] 1530630765.682889: Produced preauth for next request: 133, 138
[47700] 1530630765.682891: Encoding request body and padata into FAST request
[47700] 1530630765.682951: Sending request (1118 bytes) to MYREALM
[47700] 1530630765.682967: Resolving hostname ipamasterhostname
[47700] 1530630765.683098: Initiating TCP connection to stream ipamasterIP:88
[47700] 1530630765.683180: Sending TCP request to stream ipamasterIP:88
[47700] 1530630765.756232: Received answer from stream ipamasterIP:88
[47700] 1530630765.756302: Response was from master KDC
[47700] 1530630765.756321: Received error from KDC: -1765328360/Preauthentication failed
[47700] 1530630765.756325: Decoding FAST response
[47700] 1530630765.756376: Preauth tryagain input types: 136, 19, 138, 133, 137
kpasswd: Preauthentication failed getting initial ticket
)
2018-07-03 17:12:45,757;INFO;sortie err cmd : None)
2018-07-03 17:12:45,863;INFO;login = test_user, one_time_password = Kk)4YIRq, password = fJ6f4%(5
2018-07-03 17:12:45,503;INFO;3rd kpasswd try
2018-07-03 17:12:45,963;INFO;kpasswd stdout : [47711] 1530630765.866915: Getting initial credentials for test_user@MYREALM
[47711] 1530630765.867035: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47711] 1530630765.867075: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47711] 1530630765.867081: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47711] 1530630765.867083: Using FAST due to armor ccache negotiation result
[47711] 1530630765.867093: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47711] 1530630765.867123: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47711] 1530630765.867144: Armor ccache sesion key: aes256-cts/2559
[47711] 1530630765.867171: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/AD04, session key aes256-cts/2559
[47711] 1530630765.867244: FAST armor key: aes256-cts/D781
[47711] 1530630765.867255: Setting initial creds service to kadmin/changepw
[47711] 1530630765.867260: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47711] 1530630765.867286: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47711] 1530630765.867289: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47711] 1530630765.867291: Using FAST due to armor ccache negotiation result
[47711] 1530630765.867298: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47711] 1530630765.867320: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47711] 1530630765.867326: Armor ccache sesion key: aes256-cts/2559
[47711] 1530630765.867337: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/5503, session key aes256-cts/2559
[47711] 1530630765.867368: FAST armor key: aes256-cts/6759
[47711] 1530630765.867379: Encoding request body and padata into FAST request
[47711] 1530630765.867413: Sending request (1019 bytes) to MYREALM
[47711] 1530630765.867490: Resolving hostname ipamasterhostname
[47711] 1530630765.867714: Initiating TCP connection to stream ipamasterIP:88
[47711] 1530630765.867854: Sending TCP request to stream ipamasterIP:88
[47711] 1530630765.895839: Received answer from stream ipamasterIP:88
[47711] 1530630765.895877: Response was from master KDC
[47711] 1530630765.895920: Received error from KDC: -1765328359/Additional pre-authentication required
[47711] 1530630765.895944: Decoding FAST response
[47711] 1530630765.896007: Processing preauth types: 136, 19, 138, 133, 137
[47711] 1530630765.896016: Received cookie: MIT
Password for test_user@MYREALM: [47711] 1530630765.903391: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
[47711] 1530630765.903395: Produced preauth for next request: 133, 138
[47711] 1530630765.903397: Encoding request body and padata into FAST request
[47711] 1530630765.903444: Sending request (1118 bytes) to MYREALM
[47711] 1530630765.903458: Resolving hostname ipamasterhostname
[47711] 1530630765.903578: Initiating TCP connection to stream ipamasterIP:88
[47711] 1530630765.903702: Sending TCP request to stream ipamasterIP:88
[47711] 1530630765.963169: Received answer from stream ipamasterIP:88
[47711] 1530630765.963218: Response was from master KDC
[47711] 1530630765.963230: Received error from KDC: -1765328360/Preauthentication failed
[47711] 1530630765.963234: Decoding FAST response
[47711] 1530630765.963268: Preauth tryagain input types: 136, 19, 138, 133, 137
kpasswd: Preauthentication failed getting initial ticket
)
2018-07-03 17:12:45,964;INFO;sortie err cmd : None)
2018-07-03 17:12:46,072;INFO;Action 'user-unlock' for user test_user ended with the following summary : Unlocked account " test_user"
2018-07-03 17:12:46,072;INFO;login = test_user, one_time_password = Kk)4YIRq, password = fJ6f4%(5
2018-07-03 17:12:45,503;INFO;4th kpasswd try
2018-07-03 17:12:46,294;INFO;kpasswd stdout : [47717] 1530630766.75265: Getting initial credentials for test_user@MYREALM
[47717] 1530630766.75375: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47717] 1530630766.75413: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47717] 1530630766.75418: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47717] 1530630766.75420: Using FAST due to armor ccache negotiation result
[47717] 1530630766.75430: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47717] 1530630766.75456: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47717] 1530630766.75471: Armor ccache sesion key: aes256-cts/2559
[47717] 1530630766.75497: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/0E9B, session key aes256-cts/2559
[47717] 1530630766.75567: FAST armor key: aes256-cts/99B6
[47717] 1530630766.75578: Setting initial creds service to kadmin/changepw
[47717] 1530630766.75582: FAST armor ccache: FILE:/tmp/krb5cc_testuser
[47717] 1530630766.75606: Retrieving admin@MYREALM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MYREALM\@MYREALM@X-CACHECONF: from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47717] 1530630766.75610: Read config in FILE:/tmp/krb5cc_testuser for krbtgt/MYREALM@MYREALM: fast_avail: yes
[47717] 1530630766.75611: Using FAST due to armor ccache negotiation result
[47717] 1530630766.75617: Getting credentials admin@MYREALM -> krbtgt/MYREALM@MYREALM using ccache FILE:/tmp/krb5cc_testuser
[47717] 1530630766.75641: Retrieving admin@MYREALM -> krbtgt/MYREALM@MYREALM from FILE:/tmp/krb5cc_testuser with result: 0/Success
[47717] 1530630766.75647: Armor ccache sesion key: aes256-cts/2559
[47717] 1530630766.75672: Creating authenticator for admin@MYREALM -> krbtgt/MYREALM@MYREALM, seqnum 0, subkey aes256-cts/CC46, session key aes256-cts/2559
[47717] 1530630766.75706: FAST armor key: aes256-cts/CC9E
[47717] 1530630766.75717: Encoding request body and padata into FAST request
[47717] 1530630766.75753: Sending request (1019 bytes) to MYREALM
[47717] 1530630766.75829: Resolving hostname ipamasterhostname
[47717] 1530630766.75968: Initiating TCP connection to stream ipamasterIP:88
[47717] 1530630766.76081: Sending TCP request to stream ipamasterIP:88
[47717] 1530630766.131982: Received answer from stream ipamasterIP:88
[47717] 1530630766.132069: Response was from master KDC
[47717] 1530630766.132108: Received error from KDC: -1765328359/Additional pre-authentication required
[47717] 1530630766.132120: Decoding FAST response
[47717] 1530630766.132198: Processing preauth types: 136, 19, 138, 133, 137
[47717] 1530630766.132209: Selected etype info: etype aes256-cts, salt ")(DFnJ,r6Rx!Y#'D", params ""
[47717] 1530630766.132212: Received cookie: MIT
Password for test_user@MYREALM: [47717] 1530630766.139327: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
[47717] 1530630766.139330: Produced preauth for next request: 133, 138
[47717] 1530630766.139333: Encoding request body and padata into FAST request
[47717] 1530630766.139384: Sending request (1118 bytes) to MYREALM
[47717] 1530630766.139396: Resolving hostname ipamasterhostname
[47717] 1530630766.139522: Initiating TCP connection to stream ipamasterIP:88
[47717] 1530630766.139645: Sending TCP request to stream ipamasterIP:88
[47717] 1530630766.211079: Received answer from stream ipamasterIP:88
[47717] 1530630766.211157: Response was from master KDC
[47717] 1530630766.211190: Decoding FAST response
[47717] 1530630766.211299: Processing preauth types: 19, 138
[47717] 1530630766.211310: Selected etype info: etype aes256-cts, salt ")(DFnJ,r6Rx!Y#'D", params ""
[47717] 1530630766.211380: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
[47717] 1530630766.211396: Produced preauth for next request: (empty)
[47717] 1530630766.211400: AS key determined by preauth: aes256-cts/23C9
[47717] 1530630766.211412: FAST reply key: aes256-cts/9E0D
[47717] 1530630766.211432: Decrypted AS reply; session key is: aes256-cts/2BAA
[47717] 1530630766.211443: FAST negotiation: available
Enter new password:
Enter it again: [47717] 1530630766.211515: Creating authenticator for test_user@MYREALM -> kadmin/changepw@MYREALM, seqnum 0, subkey aes256-cts/BC7C, session key aes256-cts/2BAA
[47717] 1530630766.211555: Resolving hostname ipamasterhostname
[47717] 1530630766.211748: Sending initial UDP request to dgram ipamasterIP:464
[47717] 1530630766.293996: Received answer from dgram ipamasterIP:464
[47717] 1530630766.294064: Read AP-REP, time 1530630766.211518, subkey aes256-cts/BC7C, seqnum 202122897
Password changed.
)
2018-07-03 17:12:46,294;INFO;sortie err cmd : None)
2018-07-03 17:12:46,294;INFO;END
###
What do you think about this please ?
BR.
Lune