[Freeipa-users] ipa-dnskeysyncd ipa : ERROR Login to LDAP server failed: {'desc': 'Invalid credentials'}

Wed Dec 21 12:05:07 UTC 2016

On Wed, 2016-12-21 at 08:24 +0100, Petr Spacek wrote:
> 
> You can try to add line
> KRB5_TRACE=/dev/stdout
> to
> /etc/sysconfig/ipa-dnskeysyncd

[27472] 1482320667.240500: Retrieving ipa-dnskeysyncd/server.example.com at EXAMPLE.COM from FILE:/etc/ipa/dnssec/ipa-dnskeysyncd.keytab (vno 0, enctype 0) with result: 0/Success
[27472] 1482320667.240567: Getting initial credentials for ipa-dnskeysyncd/server.example.com at EXAMPLE.COM
[27472] 1482320667.241542: Looked up etypes in keytab: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[27472] 1482320667.241619: Sending request (207 bytes) to EXAMPLE.COM
[27472] 1482320667.241952: Resolving hostname server.example.com
[27472] 1482320667.242781: Initiating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.243067: Sending TCP request to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.248018: Received answer (336 bytes) from stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.248054: Terminating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.248215: Response was from master KDC
[27472] 1482320667.248250: Received error from KDC: -1765328359/Additional pre-authentication required
[27472] 1482320667.248304: Processing preauth types: 136, 19, 2, 133
[27472] 1482320667.248317: Selected etype info: etype aes256-cts, salt "EXAMPLE.COMipa-dnskeysyncdserver.example.com", params ""
[27472] 1482320667.248327: Received cookie: MIT
[27472] 1482320667.248400: Retrieving ipa-dnskeysyncd/server.example.com at EXAMPLE.COM from FILE:/etc/ipa/dnssec/ipa-dnskeysyncd.keytab (vno 0, enctype aes256-cts) with result: 0/Success
[27472] 1482320667.248424: AS key obtained for encrypted timestamp: aes256-cts/BCCF
[27472] 1482320667.248498: Encrypted timestamp (for 1482320667.247961): plain [redacted], encrypted [redacted]
[27472] 1482320667.248512: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
[27472] 1482320667.248520: Produced preauth for next request: 133, 2
[27472] 1482320667.248540: Sending request (302 bytes) to EXAMPLE.COM
[27472] 1482320667.248561: Resolving hostname server.example.com
[27472] 1482320667.248841: Initiating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.249050: Sending TCP request to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.512953: Received answer (837 bytes) from stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.512974: Terminating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.513076: Response was from master KDC
[27472] 1482320667.513117: Processing preauth types: 19
[27472] 1482320667.513131: Selected etype info: etype aes256-cts, salt "EXAMPLE.COMipa-dnskeysyncdserver.example.com", params ""
[27472] 1482320667.513143: Produced preauth for next request: (empty)
[27472] 1482320667.513159: AS key determined by preauth: aes256-cts/BCCF
[27472] 1482320667.513244: Decrypted AS reply; session key is: aes256-cts/BD92
[27472] 1482320667.513271: FAST negotiation: available
[27472] 1482320667.513297: Initializing FILE:/tmp/ipa-dnskeysyncd.ccache with default princ ipa-dnskeysyncd/server.example.com at EXAMPLE.COM
[27472] 1482320667.513881: Storing ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krbtgt/EXAMPLE.COM at EXAMPLE.COM in FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.513974: Storing config in FILE:/tmp/ipa-dnskeysyncd.ccache for krbtgt/EXAMPLE.COM at EXAMPLE.COM: fast_avail: yes
[27472] 1482320667.514022: Storing ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/EXAMPLE.COM\@EXAMPLE.COM at X-CACHECONF: in FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.514065: Storing config in FILE:/tmp/ipa-dnskeysyncd.ccache for krbtgt/EXAMPLE.COM at EXAMPLE.COM: pa_type: 2
[27472] 1482320667.514102: Storing ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krb5_ccache_conf_data/pa_type/krbtgt\/EXAMPLE.COM\@EXAMPLE.COM at X-CACHECONF: in FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.514181: Storing config in FILE:/tmp/ipa-dnskeysyncd.ccache for : refresh_time: 1482363867
[27472] 1482320667.514220: Storing ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krb5_ccache_conf_data/refresh_time at X-CACHECONF: in FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.619828: ccselect module realm chose cache FILE:/tmp/ipa-dnskeysyncd.ccache with client principal ipa-dnskeysyncd/server.example.com at EXAMPLE.COM for server principal ldap/server.example.com at EXAMPLE.COM
[27472] 1482320667.692119: Getting credentials ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM using ccache FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.692241: Retrieving ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM from FILE:/tmp/ipa-dnskeysyncd.ccache with result: -1765328243/Matching credential not found (filename: /tmp/ipa-dnskeysyncd.ccache)
[27472] 1482320667.692330: Retrieving ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krbtgt/EXAMPLE.COM at EXAMPLE.COM from FILE:/tmp/ipa-dnskeysyncd.ccache with result: 0/Success
[27472] 1482320667.692342: Starting with TGT for client realm: ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> krbtgt/EXAMPLE.COM at EXAMPLE.COM
[27472] 1482320667.692350: Requesting tickets for ldap/server.example.com at EXAMPLE.COM, referrals on
[27472] 1482320667.692383: Generated subkey for TGS request: aes256-cts/60D5
[27472] 1482320667.692436: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
[27472] 1482320667.692530: Encoding request body and padata into FAST request
[27472] 1482320667.692611: Sending request (1023 bytes) to EXAMPLE.COM
[27472] 1482320667.692799: Resolving hostname server.example.com
[27472] 1482320667.693065: Initiating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.693299: Sending TCP request to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.697728: Received answer (973 bytes) from stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.697748: Terminating TCP connection to stream fd31:aeb1:48df:0:214:d1ff:fe13:45ac:88
[27472] 1482320667.697849: Response was from master KDC
[27472] 1482320667.697879: Decoding FAST response
[27472] 1482320667.698004: FAST reply key: aes256-cts/03A5
[27472] 1482320667.698103: TGS reply is for ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM with session key aes256-cts/F2D7
[27472] 1482320667.698130: TGS request result: 0/Success
[27472] 1482320667.698138: Received creds for desired service ldap/server.example.com at EXAMPLE.COM
[27472] 1482320667.698150: Storing ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM in FILE:/tmp/ipa-dnskeysyncd.ccache
[27472] 1482320667.698320: Creating authenticator for ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM, seqnum 370535193, subkey aes256-cts/D075, session key aes256-cts/F2D7

The only thing I see there that is concerning is:

[27472] 1482320667.692241: Retrieving ipa-dnskeysyncd/server.example.com at EXAMPLE.COM -> ldap/server.example.com at EXAMPLE.COM from FILE:/tmp/ipa-dnskeysyncd.ccache with result: -1765328243/Matching credential not found (filename: /tmp/ipa-dnskeysyncd.ccache)

Is that the problem?

Cheers,
b.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 473 bytes
Desc: This is a digitally signed message part
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20161221/fda90ae9/attachment.sig>