On (22/05/17 06:51), Joakim Tjernlund wrote:
On Fri, 2017-05-19 at 16:59 +0200, Lukas Slebodnik wrote:
On (19/05/17 14:41), Joakim Tjernlund wrote:
On Fri, 2017-05-19 at 16:34 +0200, Lukas Slebodnik wrote:
On (19/05/17 14:07), Joakim Tjernlund wrote:
Will do over the week end
Please also provide an output of following command rpm -V sssd-common sssd-krb5-common
That is a bit hard as this is Gentoo :)
Ahh sorry;
I cannot see 1.15.2 in portage. Which arguments did you pass to configure?
Sending the ebuilds I use, made by myself as upstream is lagging behind.
Logging to journald is not enabled enabled. So I do not think you fwill find anything in journald :-)
sssd is not compiled with non-privileged user therefore it should not cause problems.
We will not be able to move it forward without *child log files.
LS
Hi again
Got some *child logs now. Can you make something of these?
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x0400): ldap_child started. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): total buffer size: 49 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): got realm_str: INFINERA.COM (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): princ_str size: 13 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): got princ_str: GENTOO-LABBB$ (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x0200): Will run as [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [privileged_krb5_setup] (0x2000): Kerberos context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): Kerberos context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [become_user] (0x0200): Trying to become user [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [become_user] (0x0200): Already user [0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): Running as [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): getting TGT sync (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [GENTOO-LABBB$@INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430433: Getting initial credentials for GENTOO-LABBB$@INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430585: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc, aes128-cts, aes256-cts, rc4-hmac
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430660: Sending request (203 bytes) to INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430840: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.431709: Sending initial UDP request to dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432672: Received answer (266 bytes) from dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432741: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432786: Received error from KDC: -1765328359/Additional pre-authentication required
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432851: Processing preauth types: 16, 15, 19, 2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432880: Selected etype info: etype aes256-cts, salt "INFINERA.COMhostgentoo-labbb.infinera.com", params ""
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432923: Retrieving GENTOO-LABBB$@INFINERA.COM from MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432960: AS key obtained for encrypted timestamp: aes256-cts/645C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433059: Encrypted timestamp (for 1495435577.276052): plain 301AA011180F32303137303532323036343631375AA1050203043654, encrypted 08B7186DAB549BD6AC8DCC76C9E88A5FB59619A42672B848C1CF6605E2AB5EFB54D0EDD8B8FC3D9BC154519791BD77F8938FBADEB6C9F65C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433087: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433103: Produced preauth for next request: 2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433137: Sending request (283 bytes) to INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433172: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433387: Sending initial UDP request to dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434554: Received answer (96 bytes) from dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434603: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434624: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434636: Request or response is too big for UDP; retrying with TCP
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434647: Sending request (283 bytes) to INFINERA.COM (tcp only)
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434665: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434807: Initiating TCP connection to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.435110: Sending TCP request to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436061: Received answer (1543 bytes) from stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436086: Terminating TCP connection to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436130: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436166: Processing preauth types: 19
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436180: Selected etype info: etype aes256-cts, salt "INFINERA.COMhostgentoo-labbb.infinera.com", params ""
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436191: Produced preauth for next request: (empty)
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436204: AS key determined by preauth: aes256-cts/645C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436268: Decrypted AS reply; session key is: aes256-cts/00F2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436287: FAST negotiation: unavailable
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436396: Initializing FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb with default princ GENTOO-LABBB$@INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436543: Storing GENTOO-LABBB$@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM in FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] to [/var/lib/sss/db/ccache_INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [prepare_response] (0x0400): Building response for result [0] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [pack_buffer] (0x2000): response size: 60 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x0400): ldap_child completed successfully
(Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): krb5_child started. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x1000): total buffer size: [154] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x0100): cmd [248] uid [1001] gid [100] validate [true] enterprise principal [false] offline [false] UPN [jocke@INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [check_use_fast] (0x0100): Not using FAST. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x2000): Running as [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): Will perform ticket renewal (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [renew_tgt_child] (0x1000): Renewing a ticket (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515585: Retrieving jocke@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM from FILE:/tmp/krb5cc_1001 with result: 0/Success (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515616: Get cred via TGT krbtgt/INFINERA.COM@INFINERA.COM after requesting krbtgt/INFINERA.COM@INFINERA.COM (canonicalize off) (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515681: Generated subkey for TGS request: aes256-cts/2D54 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515747: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts, des-cbc-crc, des, des-cbc-md4 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515862: Encoding request body and padata into FAST request (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515973: Sending request (1901 bytes) to INFINERA.COM (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516194: Resolving hostname se-dc01.infinera.com (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516448: Initiating TCP connection to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516778: Sending TCP request to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517190: Received answer (123 bytes) from stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517203: Terminating TCP connection to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517247: Response was not from master KDC (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517270: Got cred; -1765328352/Ticket expired (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
(Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_send_data] (0x0200): Received error code 1432158229 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [pack_response_packet] (0x2000): response packet size: [4] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_send_data] (0x4000): Response sent. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): krb5_child completed successfully
There were 5 more attempts to renew tickets within a second. 4 of them failed due to expired ticket. And the last one failed due to offline mode.
Few seconds later (7) user was authenticated in offline mode.
(Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): krb5_child started. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x1000): total buffer size: [141] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x0100): cmd [241] uid [1001] gid [100] validate [true] enterprise principal [false] offline [true] UPN [jocke@INFINERA.COM] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [check_use_fast] (0x0100): Not using FAST. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x2000): Running as [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Already user [1001]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): Will perform offline auth (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [create_empty_ccache] (0x1000): Existing ccache still valid, reusing (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_send_data] (0x0200): Received error code 0 (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [pack_response_packet] (0x2000): response packet size: [45] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_send_data] (0x4000): Response sent. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): krb5_child completed successfully
LS
On Mon, 2017-05-22 at 16:38 +0200, Lukas Slebodnik wrote:
On (22/05/17 06:51), Joakim Tjernlund wrote:
On Fri, 2017-05-19 at 16:59 +0200, Lukas Slebodnik wrote:
On (19/05/17 14:41), Joakim Tjernlund wrote:
On Fri, 2017-05-19 at 16:34 +0200, Lukas Slebodnik wrote:
On (19/05/17 14:07), Joakim Tjernlund wrote:
Will do over the week end
> > Please also provide an output of following command > rpm -V sssd-common sssd-krb5-common
That is a bit hard as this is Gentoo :)
Ahh sorry;
I cannot see 1.15.2 in portage. Which arguments did you pass to configure?
Sending the ebuilds I use, made by myself as upstream is lagging behind.
Logging to journald is not enabled enabled. So I do not think you fwill find anything in journald :-)
sssd is not compiled with non-privileged user therefore it should not cause problems.
We will not be able to move it forward without *child log files.
LS
Hi again
Got some *child logs now. Can you make something of these? (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x0400): ldap_child started. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): total buffer size: 49 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): got realm_str: INFINERA.COM (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): princ_str size: 13 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): got princ_str: GENTOO-LABBB$ (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unpack_buffer] (0x0200): Will run as [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [privileged_krb5_setup] (0x2000): Kerberos context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): Kerberos context initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [become_user] (0x0200): Trying to become user [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [become_user] (0x0200): Already user [0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): Running as [0][0]. (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x2000): getting TGT sync (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [GENTOO-LABBB$@INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430433: Getting initial credentials for GENTOO-LABBB$@INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430585: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc, aes128-cts, aes256-cts, rc4-hmac
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430660: Sending request (203 bytes) to INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.430840: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.431709: Sending initial UDP request to dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432672: Received answer (266 bytes) from dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432741: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432786: Received error from KDC: -1765328359/Additional pre-authentication required
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432851: Processing preauth types: 16, 15, 19, 2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432880: Selected etype info: etype aes256-cts, salt "INFINERA.COMhostgentoo-labbb.infinera.com", params ""
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432923: Retrieving GENTOO-LABBB$@INFINERA.COM from MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.432960: AS key obtained for encrypted timestamp: aes256-cts/645C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433059: Encrypted timestamp (for 1495435577.276052): plain 301AA011180F32303137303532323036343631375AA1050203043654, encrypted 08B7186DAB549BD6AC8DCC76C9E88A5FB59619A42672B848C1CF6605E2AB5EFB54D0EDD8B8FC3D9BC154519791BD77F8938FBADEB6C9F65C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433087: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433103: Produced preauth for next request: 2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433137: Sending request (283 bytes) to INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433172: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.433387: Sending initial UDP request to dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434554: Received answer (96 bytes) from dgram 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434603: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434624: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434636: Request or response is too big for UDP; retrying with TCP
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434647: Sending request (283 bytes) to INFINERA.COM (tcp only)
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434665: Resolving hostname se-dc01.infinera.com
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.434807: Initiating TCP connection to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.435110: Sending TCP request to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436061: Received answer (1543 bytes) from stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436086: Terminating TCP connection to stream 10.210.34.21:88
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436130: Response was not from master KDC
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436166: Processing preauth types: 19
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436180: Selected etype info: etype aes256-cts, salt "INFINERA.COMhostgentoo-labbb.infinera.com", params ""
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436191: Produced preauth for next request: (empty)
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436204: AS key determined by preauth: aes256-cts/645C
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436268: Decrypted AS reply; session key is: aes256-cts/00F2
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436287: FAST negotiation: unavailable
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436396: Initializing FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb with default princ GENTOO-LABBB$@INFINERA.COM
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [sss_child_krb5_trace_cb] (0x4000): [17650] 1495435574.436543: Storing GENTOO-LABBB$@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM in FILE:/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
(Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] to [/var/lib/sss/db/ccache_INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/db/ccache_INFINERA.COM_wwO4jb] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [prepare_response] (0x0400): Building response for result [0] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [pack_buffer] (0x2000): response size: 60 (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[ldap_child[17650]]]] [main] (0x0400): ldap_child completed successfully (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): krb5_child started. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x1000): total buffer size: [154] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x0100): cmd [248] uid [1001] gid [100] validate [true] enterprise principal [false] offline [false] UPN [jocke@INFINERA.COM] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [check_use_fast] (0x0100): Not using FAST. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x2000): Running as [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): Will perform ticket renewal (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [renew_tgt_child] (0x1000): Renewing a ticket (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515585: Retrieving jocke@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM from FILE:/tmp/krb5cc_1001 with result: 0/Success (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515616: Get cred via TGT krbtgt/INFINERA.COM@INFINERA.COM after requesting krbtgt/INFINERA.COM@INFINERA.COM (canonicalize off) (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515681: Generated subkey for TGS request: aes256-cts/2D54 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515747: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts, des-cbc-crc, des, des-cbc-md4 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515862: Encoding request body and padata into FAST request (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.515973: Sending request (1901 bytes) to INFINERA.COM (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516194: Resolving hostname se-dc01.infinera.com (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516448: Initiating TCP connection to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.516778: Sending TCP request to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517190: Received answer (123 bytes) from stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517203: Terminating TCP connection to stream 10.210.34.21:88 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517247: Response was not from master KDC (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [sss_child_krb5_trace_cb] (0x4000): [17652] 1495435574.517270: Got cred; -1765328352/Ticket expired (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
(Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_send_data] (0x0200): Received error code 1432158229 (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [pack_response_packet] (0x2000): response packet size: [4] (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [k5c_send_data] (0x4000): Response sent. (Mon May 22 08:46:14 2017) [[sssd[krb5_child[17652]]]] [main] (0x0400): krb5_child completed successfully
There were 5 more attempts to renew tickets within a second. 4 of them failed due to expired ticket. And the last one failed due to offline mode.
Few seconds later (7) user was authenticated in offline mode.
(Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): krb5_child started. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x1000): total buffer size: [141] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x0100): cmd [241] uid [1001] gid [100] validate [true] enterprise principal [false] offline [true] UPN [jocke@INFINERA.COM] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [check_use_fast] (0x0100): Not using FAST. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x2000): Running as [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [become_user] (0x0200): Already user [1001]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): Will perform offline auth (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [create_empty_ccache] (0x1000): Existing ccache still valid, reusing (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_send_data] (0x0200): Received error code 0 (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [pack_response_packet] (0x2000): response packet size: [45] (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [k5c_send_data] (0x4000): Response sent. (Mon May 22 08:46:21 2017) [[sssd[krb5_child[17694]]]] [main] (0x0400): krb5_child completed successfully
LS _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
sssctl domain-status example.com Online status: Online
Active servers: KPASSWD: not connected KERBEROS: not connected LDAP: ldap.abc.example.com
Discovered KPASSWD servers: - kerberos.abc.example.com
Discovered KERBEROS servers: - kerberos.abc.example.com
Discovered LDAP servers: - ldap.abc.example.com - ldap.corp.example.com
LS
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
sssctl domain-status example.com Online status: Online Active servers: KPASSWD: not connected KERBEROS: not connected LDAP: ldap.abc.example.com Discovered KPASSWD servers: - kerberos.abc.example.com Discovered KERBEROS servers: - kerberos.abc.example.com Discovered LDAP servers: - ldap.abc.example.com - ldap.corp.example.comLS _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
On another machine I added ifp to services and just reloaded the sssd config (signal HUG to sssd) and just got this in the domain log: (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [be_primary_server_timeout] (0x0400): Looking for primary server! (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [get_server_status] (0x1000): Status of server 'se-dc02.infinera.com' is 'working' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [get_port_status] (0x1000): Port status of port 0 for server 'se-dc02.infinera.com' is 'not working' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [get_port_status] (0x0100): Resetting the status of port 0 for server 'se-dc02.infinera.com' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [get_server_status] (0x1000): Status of server 'se-dc02.infinera.com' is 'working' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [be_resolve_server_process] (0x0200): Found address for server se-dc02.infinera.com: [10.210.34.22] TTL 3600 (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://se-dc02.infinera.com' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://se-dc02.infinera.com' (Tue May 23 10:15:29 2017) [sssd[be[infinera.com]]] [be_run_reconnect_cb] (0x0400): Reconnecting. Running callbacks.
and later
(Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, GENTOO-LABBB$, INFINERA.COM, 86400) (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [get_server_status] (0x1000): Status of server 'se-dc02.infinera.com' is 'name resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [get_port_status] (0x1000): Port status of port 0 for server 'se-dc02.infinera.com' is 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [get_server_status] (0x1000): Status of server 'se-dc02.infinera.com' is 'name resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_resolve_server_process] (0x0200): Found address for server se-dc02.infinera.com: [10.210.34.22] TTL 3600 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 49 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [30118] (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [child_handler_setup] (0x2000): Signal handler set up for pid [30118] (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_process_result] (0x2000): Trace: sh[0x9cadd0], connected[1], ops[(nil)], ldap[0x990c40] (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [child_sig_handler] (0x1000): Waiting for child [30118]. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [child_sig_handler] (0x0100): child [30118] finished successfully. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_INFINERA.COM], expired on [1495563696] (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1495528596 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: GENTOO-LABBB$ (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called from: src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_recv: 2067 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'se-dc02.infinera.com' as 'working' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'se-dc02.infinera.com' as 'working' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'se-dc02.infinera.com' as 'working' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sdap_handle_release] (0x2000): Trace: sh[0x9cadd0], connected[1], ops[(nil)], ldap[0x990c40], destructor_lock[0], release_memory[0] (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [dp_req_done] (0x0400): DP Request [Online Check #83]: Request handler finished [0]: Success (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [_dp_req_recv] (0x0400): DP Request [Online Check #83]: Receiving request data. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [dp_req_destructor] (0x0400): DP Request [Online Check #83]: Request removed. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_check_online_done] (0x0400): Error during online check [0]: Success (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_reset_services] (0x1000): Resetting all servers in all services (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'se-dc02.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'se-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'se-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'se-dc01.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'se-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'se-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'sv-dc02.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'sv-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'sv-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'sv-dc01.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'sv-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'sv-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'se-dc02.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'se-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'se-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'se-dc01.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'se-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'se-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'sv-dc02.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'sv-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'sv-dc02.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [set_server_common_status] (0x0100): Marking server 'sv-dc01.infinera.com' as 'name not resolved' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'sv-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server 'sv-dc01.infinera.com' as 'neutral' (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [reactivate_subdoms] (0x1000): Resetting all subdomains (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [sss_domain_get_state] (0x1000): Domain infinera.com is Active (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_ptask_disable] (0x0400): Task [Check if online (periodic)]: disabling task (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_run_online_cb] (0x0080): Going online. Running callbacks. (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_ptask_online_cb] (0x0400): Back end is online (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_ptask_enable] (0x0400): Task [Subdomains Refresh]: enabling task (Tue May 23 10:21:36 2017) [sssd[be[infinera.com]]] [be_ptask_schedule] (0x0400): Task [Subdomains Refresh]: scheduling task 0 seconds from now [1495527696]
but krb5_child log just repeats:
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [renew_tgt_child] (0x1000): Renewing a ticket (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638731: Retrieving jocke@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM from FILE:/tmp/krb5cc_1001 with result: 0/Success
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638747: Get cred via TGT krbtgt/INFINERA.COM@INFINERA.COM after requesting krbtgt/INFINERA.COM@INFINERA.COM (canonicalize off)
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638788: Generated subkey for TGS request: aes256-cts/3F94
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638841: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts, des-cbc-crc, des, des-cbc-md4
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638944: Encoding request body and padata into FAST request
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639036: Sending request (1901 bytes) to INFINERA.COM
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639179: Resolving hostname se-dc01.infinera.com
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639483: Initiating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639888: Sending TCP request to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640356: Received answer (123 bytes) from stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640375: Terminating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [k5c_send_data] (0x0200): Received error code 1432158229 (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [pack_response_packet] (0x2000): response packet size: [4] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [k5c_send_data] (0x4000): Response sent. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [main] (0x0400): krb5_child completed successfully (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [main] (0x0400): krb5_child started. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [unpack_buffer] (0x1000): total buffer size: [154] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [unpack_buffer] (0x0100): cmd [248] uid [1001] gid [100] validate [true] enterprise principal [false] offline [false] UPN [jocke@INFINERA.COM] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [check_use_fast] (0x0100): Not using FAST. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [main] (0x2000): Running as [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [main] (0x0400): Will perform ticket renewal (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [renew_tgt_child] (0x1000): Renewing a ticket (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647807: Retrieving jocke@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM from FILE:/tmp/krb5cc_1001 with result: 0/Success
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647819: Get cred via TGT krbtgt/INFINERA.COM@INFINERA.COM after requesting krbtgt/INFINERA.COM@INFINERA.COM (canonicalize off)
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647845: Generated subkey for TGS request: aes256-cts/37F1
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647884: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts, des-cbc-crc, des, des-cbc-md4
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647941: Encoding request body and padata into FAST request
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.647990: Sending request (1901 bytes) to INFINERA.COM
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.648096: Resolving hostname se-dc01.infinera.com
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.648529: Initiating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.648973: Sending TCP request to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.649464: Received answer (123 bytes) from stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.649480: Terminating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.649516: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [sss_child_krb5_trace_cb] (0x4000): [30165] 1495527829.649532: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [k5c_send_data] (0x0200): Received error code 1432158229 (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [pack_response_packet] (0x2000): response packet size: [4] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [k5c_send_data] (0x4000): Response sent. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30165]]]] [main] (0x0400): krb5_child completed successfully (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [main] (0x0400): krb5_child started. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [unpack_buffer] (0x1000): total buffer size: [154] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [unpack_buffer] (0x0100): cmd [248] uid [1001] gid [100] validate [true] enterprise principal [false] offline [false] UPN [jocke@INFINERA.COM] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1001] old_ccname: [FILE:/tmp/krb5cc_1001] keytab: [/etc/krb5.keytab] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [check_use_fast] (0x0100): Not using FAST. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [switch_creds] (0x0200): Switch user to [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1001] and is active and TGT is valid. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [become_user] (0x0200): Trying to become user [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [main] (0x2000): Running as [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [k5c_setup] (0x2000): Running as [1001][100]. (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [set_lifetime_options] (0x0100): Renewable lifetime is set to [7d] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [set_lifetime_options] (0x0100): Lifetime is set to [24h] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30166]]]] [main] (0x0400): Will perform ticket renewal
The network is just fine.
Jocke
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
On another machine I added ifp to services and just reloaded the sssd config (signal HUG to sssd) and just got this in the domain log:
The only way how sssd can use new configuration is to RESTART sssd. sssd does not reload configuration after receiving SIGHUP.
LS
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
but krb5_child log just repeats:
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [renew_tgt_child] (0x1000): Renewing a ticket (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638731: Retrieving jocke@INFINERA.COM -> krbtgt/INFINERA.COM@INFINERA.COM from FILE:/tmp/krb5cc_1001 with result: 0/Success
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638747: Get cred via TGT krbtgt/INFINERA.COM@INFINERA.COM after requesting krbtgt/INFINERA.COM@INFINERA.COM (canonicalize off)
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638788: Generated subkey for TGS request: aes256-cts/3F94
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638841: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts, des-cbc-crc, des, des-cbc-md4
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.638944: Encoding request body and padata into FAST request
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639036: Sending request (1901 bytes) to INFINERA.COM
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639179: Resolving hostname se-dc01.infinera.com
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639483: Initiating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.639888: Sending TCP request to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640356: Received answer (123 bytes) from stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640375: Terminating TCP connection to stream 10.210.34.21:88
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
LS
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
but krb5_child log just repeats:
[SNIP]
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
Jocke
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
> The time is not synchronised between client and server. > MIT krb5 can handle small offset. But I would highly recommends > to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
> Renewing of a ticket failed because it is already expired. > Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
but krb5_child log just repeats:
[SNIP]
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
LS
On Tue, 2017-05-23 at 11:40 +0200, Lukas Slebodnik wrote:
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote: > > The time is not synchronised between client and server. > > MIT krb5 can handle small offset. But I would highly recommends > > to keep time in sync. > > There is some time problem on and off but this has never been too much. I don't > think this was the root problem here ? >
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
> > Renewing of a ticket failed because it is already expired. > > Maybe due to time shift between client and server(KDC) > > Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for > the ticket to expire(10 hours here) and then woke up and unlocked the screen. > The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. > Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket. >
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
but krb5_child log just repeats:
[SNIP]
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
Right, this seems to be the right thing anyhow, mapping these to errors to network IO error does seem odd.
While I am at it, if you look in the ebuild I sent earlier you will find: append-libs "-ldl" This is because sssd underlinks wbclient, without -ldl I get runtime error, cannot find dlopen" (or similar to that msg)
Jocke
On Tue, May 23, 2017 at 01:03:49PM +0000, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:40 +0200, Lukas Slebodnik wrote:
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote: > On (22/05/17 14:53), Joakim Tjernlund wrote: > > > The time is not synchronised between client and server. > > > MIT krb5 can handle small offset. But I would highly recommends > > > to keep time in sync. > > > > There is some time problem on and off but this has never been too much. I don't > > think this was the root problem here ? > > > > As I already mention I would highly recommend to keep time in sync. > It will reduce possible errors. > > Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
> > > > > Renewing of a ticket failed because it is already expired. > > > Maybe due to time shift between client and server(KDC) > > > > Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for > > the ticket to expire(10 hours here) and then woke up and unlocked the screen. > > The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. > > Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket. > > > > sssd would get new ticket if it was in online mode. > But it offline mode. > > I would highly recommend to keep time in sync with server > and then debug why sssd was in offline mode. > Or why it went to offline mode. > > With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
Jocke
but krb5_child log just repeats:
[SNIP]
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
Right, this seems to be the right thing anyhow, mapping these to errors to network IO error does seem odd.
So what would you propose the deamon does if libkrb5 tells it that the server is out of sync?
While I am at it, if you look in the ebuild I sent earlier you will find: append-libs "-ldl" This is because sssd underlinks wbclient, without -ldl I get runtime error, cannot find dlopen" (or similar to that msg)
Jocke _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On Tue, 2017-05-23 at 15:31 +0200, Jakub Hrozek wrote:
On Tue, May 23, 2017 at 01:03:49PM +0000, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:40 +0200, Lukas Slebodnik wrote:
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote: > On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote: > > On (22/05/17 14:53), Joakim Tjernlund wrote: > > > > The time is not synchronised between client and server. > > > > MIT krb5 can handle small offset. But I would highly recommends > > > > to keep time in sync. > > > > > > There is some time problem on and off but this has never been too much. I don't > > > think this was the root problem here ? > > > > > > > As I already mention I would highly recommend to keep time in sync. > > It will reduce possible errors. > > > > Configure ntpd/chrony on client and server is not a rocket science :-) > > Sure, no rocket science but I have little control over the AD servers. :( > Anyhow, I did a "net ads info" and it came back with Server time offset: 0 > so I don't think there is a time difference(or very small)? > The clients are already on NTP. > > > > > > > > > Renewing of a ticket failed because it is already expired. > > > > Maybe due to time shift between client and server(KDC) > > > > > > Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for > > > the ticket to expire(10 hours here) and then woke up and unlocked the screen. > > > The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. > > > Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket. > > > > > > > sssd would get new ticket if it was in online mode. > > But it offline mode. > > > > I would highly recommend to keep time in sync with server > > and then debug why sssd was in offline mode. > > Or why it went to offline mode. > > > > With 1.15 you can use sssctl e.g. > > I did run sssctl domain-status infinera.com and it came back with: > Unable to get online status [3]: Communication error > org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application > did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the > network connection was broken. > Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' > option in sssd.conf. > Unable to get online status > > I then just added 'ifp' to 'services' and restarted sssd and now it works: > sssctl domain-status infinera.com > Online status: Online > > Active servers: > AD Global Catalog: not connected > AD Domain Controller: se-dc01.infinera.com > ..... > > Could the problem I saw be related to not having ifp in services ? > I will check again when the ticket expires again. > > Jocke
but krb5_child log just repeats:
[SNIP]
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired
(Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
Right, this seems to be the right thing anyhow, mapping these to errors to network IO error does seem odd.
So what would you propose the deamon does if libkrb5 tells it that the server is out of sync?
Not sure, possibly the same as now but it should be handled separately so one can differentiate(don't pretend it is an network error).
While I am at it, if you look in the ebuild I sent earlier you will find: append-libs "-ldl" This is because sssd underlinks wbclient, without -ldl I get runtime error, cannot find dlopen" (or similar to that msg)
Jocke _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On Tue, 2017-05-23 at 15:45 +0200, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 15:31 +0200, Jakub Hrozek wrote:
On Tue, May 23, 2017 at 01:03:49PM +0000, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:40 +0200, Lukas Slebodnik wrote:
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote:
On (23/05/17 08:39), Joakim Tjernlund wrote: > On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote: > > On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote: > > > On (22/05/17 14:53), Joakim Tjernlund wrote: > > > > > The time is not synchronised between client and server. > > > > > MIT krb5 can handle small offset. But I would highly recommends > > > > > to keep time in sync. > > > > > > > > There is some time problem on and off but this has never been too much. I don't > > > > think this was the root problem here ? > > > > > > > > > > As I already mention I would highly recommend to keep time in sync. > > > It will reduce possible errors. > > > > > > Configure ntpd/chrony on client and server is not a rocket science :-) > > > > Sure, no rocket science but I have little control over the AD servers. :( > > Anyhow, I did a "net ads info" and it came back with Server time offset: 0 > > so I don't think there is a time difference(or very small)? > > The clients are already on NTP. > > > > > > > > > > > > > Renewing of a ticket failed because it is already expired. > > > > > Maybe due to time shift between client and server(KDC) > > > > > > > > Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for > > > > the ticket to expire(10 hours here) and then woke up and unlocked the screen. > > > > The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. > > > > Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket. > > > > > > > > > > sssd would get new ticket if it was in online mode. > > > But it offline mode. > > > > > > I would highly recommend to keep time in sync with server > > > and then debug why sssd was in offline mode. > > > Or why it went to offline mode. > > > > > > With 1.15 you can use sssctl e.g. > > > > I did run sssctl domain-status infinera.com and it came back with: > > Unable to get online status [3]: Communication error > > org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application > > did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the > > network connection was broken. > > Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' > > option in sssd.conf. > > Unable to get online status > > > > I then just added 'ifp' to 'services' and restarted sssd and now it works: > > sssctl domain-status infinera.com > > Online status: Online > > > > Active servers: > > AD Global Catalog: not connected > > AD Domain Controller: se-dc01.infinera.com > > ..... > > > > Could the problem I saw be related to not having ifp in services ? > > I will check again when the ticket expires again. > > > > Jocke > > but krb5_child log just repeats: >
[SNIP]
> > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC > > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired > > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired]
The most confusing for me was a reason why we went offline. And after checking the source code I found out a reason.
We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error (ERR_NETWORK_IO) since 1.14.2
https://pagure.io/SSSD/sssd/issue/3174 https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64
It might be a reasonable with first kinit. Because new ticket should be valid. But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
Thank you very much for bug report. And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
Right, this seems to be the right thing anyhow, mapping these to errors to network IO error does seem odd.
So what would you propose the deamon does if libkrb5 tells it that the server is out of sync?
Not sure, possibly the same as now but it should be handled separately so one can differentiate(don't pretend it is an network error).
hmm, what will happen now that I have reverted the above patch w.r.t KRB5KRB_AP_ERR_TKT_EXPIRED ? Will sssd not let me in at all unless I get a network connection to the AD?
Jocke
On Tue, 2017-05-23 at 17:40 +0200, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 15:45 +0200, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 15:31 +0200, Jakub Hrozek wrote:
On Tue, May 23, 2017 at 01:03:49PM +0000, Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:40 +0200, Lukas Slebodnik wrote:
On (23/05/17 09:19), Joakim Tjernlund wrote:
On Tue, 2017-05-23 at 11:07 +0200, Lukas Slebodnik wrote: > On (23/05/17 08:39), Joakim Tjernlund wrote: > > On Tue, 2017-05-23 at 10:11 +0200, Joakim Tjernlund wrote: > > > On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote: > > > > On (22/05/17 14:53), Joakim Tjernlund wrote: > > > > > > The time is not synchronised between client and server. > > > > > > MIT krb5 can handle small offset. But I would highly recommends > > > > > > to keep time in sync. > > > > > > > > > > There is some time problem on and off but this has never been too much. I don't > > > > > think this was the root problem here ? > > > > > > > > > > > > > As I already mention I would highly recommend to keep time in sync. > > > > It will reduce possible errors. > > > > > > > > Configure ntpd/chrony on client and server is not a rocket science :-) > > > > > > Sure, no rocket science but I have little control over the AD servers. :( > > > Anyhow, I did a "net ads info" and it came back with Server time offset: 0 > > > so I don't think there is a time difference(or very small)? > > > The clients are already on NTP. > > > > > > > > > > > > > > > > > Renewing of a ticket failed because it is already expired. > > > > > > Maybe due to time shift between client and server(KDC) > > > > > > > > > > Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for > > > > > the ticket to expire(10 hours here) and then woke up and unlocked the screen. > > > > > The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. > > > > > Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket. > > > > > > > > > > > > > sssd would get new ticket if it was in online mode. > > > > But it offline mode. > > > > > > > > I would highly recommend to keep time in sync with server > > > > and then debug why sssd was in offline mode. > > > > Or why it went to offline mode. > > > > > > > > With 1.15 you can use sssctl e.g. > > > > > > I did run sssctl domain-status infinera.com and it came back with: > > > Unable to get online status [3]: Communication error > > > org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application > > > did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the > > > network connection was broken. > > > Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' > > > option in sssd.conf. > > > Unable to get online status > > > > > > I then just added 'ifp' to 'services' and restarted sssd and now it works: > > > sssctl domain-status infinera.com > > > Online status: Online > > > > > > Active servers: > > > AD Global Catalog: not connected > > > AD Domain Controller: se-dc01.infinera.com > > > ..... > > > > > > Could the problem I saw be related to not having ifp in services ? > > > I will check again when the ticket expires again. > > > > > > Jocke > > > > but krb5_child log just repeats: > >
[SNIP]
> > > > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640416: Response was not from master KDC > > > > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [sss_child_krb5_trace_cb] (0x4000): [30164] 1495527829.640436: Got cred; -1765328352/Ticket expired > > > > (Tue May 23 10:23:49 2017) [[sssd[krb5_child[30164]]]] [map_krb5_error] (0x0020): 1643: [-1765328352][Ticket expired] > > The most confusing for me was a reason why we went offline. > And after checking the source code I found out a reason. > > We map expired ticket(KRB5KRB_AP_ERR_TKT_EXPIRED) to network error > (ERR_NETWORK_IO) since 1.14.2 > > https://pagure.io/SSSD/sssd/issue/3174 > https://pagure.io/SSSD/sssd/c/d3348f49260998880bb7cd3b2fb72d562b1b7a64 > > It might be a reasonable with first kinit. Because new ticket should be valid. > But we should treat it differently for renewing ticket.
Ahh, nice. I wonder though if there could be a short wait for the network to come on? Usually the unlock window is presented shortly before network is on so when fast unlock sssd will be offline and no new ticket which causes some grief for users.
> > Thank you very much for bug report. > And sorry that it took me so long to find a bug.
NP, glad you found something. Please send patch my way, I will test it directly.
ATM I do not have a higher priority tasks. And I am not sure when someone from developers will have a time to fix it.
The fastest workaround should be to revert the patch d3348f49260998880bb7cd3b2fb72d562b1b7a64.
Right, this seems to be the right thing anyhow, mapping these to errors to network IO error does seem odd.
So what would you propose the deamon does if libkrb5 tells it that the server is out of sync?
Not sure, possibly the same as now but it should be handled separately so one can differentiate(don't pretend it is an network error).
hmm, what will happen now that I have reverted the above patch w.r.t KRB5KRB_AP_ERR_TKT_EXPIRED ? Will sssd not let me in at all unless I get a network connection to the AD?
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
On Mon, May 29, 2017 at 01:45:00PM +0000, Joakim Tjernlund wrote:
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
Hi Joakim, could you please test if this commit: https://github.com/SSSD/sssd/compare/master...jhrozek:renew-offline also fixes the problem for you?
Thank you..
On Wed, 2017-07-19 at 16:28 +0200, Jakub Hrozek wrote:
On Mon, May 29, 2017 at 01:45:00PM +0000, Joakim Tjernlund wrote:
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
Hi Joakim, could you please test if this commit: https://github.com/SSSD/sssd/compare/master...jhrozek:renew-offline also fixes the problem for you?
Thank you..
Sure, what is the clone/branch URL for this? It is not visible on that page.
On Wed, 2017-07-19 at 16:42 +0200, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 16:28 +0200, Jakub Hrozek wrote:
On Mon, May 29, 2017 at 01:45:00PM +0000, Joakim Tjernlund wrote:
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
Hi Joakim, could you please test if this commit: https://github.com/SSSD/sssd/compare/master...jhrozek:renew-offline also fixes the problem for you?
Thank you..
Sure, what is the clone/branch URL for this? It is not visible on that page.
Found it ...
On Wed, 2017-07-19 at 17:34 +0200, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 16:42 +0200, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 16:28 +0200, Jakub Hrozek wrote:
On Mon, May 29, 2017 at 01:45:00PM +0000, Joakim Tjernlund wrote:
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
Hi Joakim, could you please test if this commit: https://github.com/SSSD/sssd/compare/master...jhrozek:renew-offline also fixes the problem for you?
Thank you..
Sure, what is the clone/branch URL for this? It is not visible on that page.
Found it ...
Tested over night and login after all night suspend worked, thanks.
Jocke
On Thu, Jul 20, 2017 at 07:32:24AM +0000, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 17:34 +0200, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 16:42 +0200, Joakim Tjernlund wrote:
On Wed, 2017-07-19 at 16:28 +0200, Jakub Hrozek wrote:
On Mon, May 29, 2017 at 01:45:00PM +0000, Joakim Tjernlund wrote:
FYI, after reverting d3348f49260998880bb7cd3b2fb72d562b1b7a64 our expired ticket problem is no more.
Jocke
Hi Joakim, could you please test if this commit: https://github.com/SSSD/sssd/compare/master...jhrozek:renew-offline also fixes the problem for you?
Thank you..
Sure, what is the clone/branch URL for this? It is not visible on that page.
Found it ...
Tested over night and login after all night suspend worked, thanks.
Thank you very much for testing, I submitted the patch as https://github.com/SSSD/sssd/pull/328
I think we can release 1.15.3 once this PR and https://github.com/SSSD/sssd/pull/327 are merged..
On (23/05/17 08:11), Joakim Tjernlund wrote:
On Mon, 2017-05-22 at 22:29 +0200, Lukas Slebodnik wrote:
On (22/05/17 14:53), Joakim Tjernlund wrote:
The time is not synchronised between client and server. MIT krb5 can handle small offset. But I would highly recommends to keep time in sync.
There is some time problem on and off but this has never been too much. I don't think this was the root problem here ?
As I already mention I would highly recommend to keep time in sync. It will reduce possible errors.
Configure ntpd/chrony on client and server is not a rocket science :-)
Sure, no rocket science but I have little control over the AD servers. :( Anyhow, I did a "net ads info" and it came back with Server time offset: 0 so I don't think there is a time difference(or very small)? The clients are already on NTP.
Renewing of a ticket failed because it is already expired. Maybe due to time shift between client and server(KDC)
Yes, it is expired to begin with. I got a ticket, then suspended the computer long enough for the ticket to expire(10 hours here) and then woke up and unlocked the screen. The problem is that sssd never tries to get a new ticket using my creds I gave when unlocking. Even if I do several lock/unlocks after the network is restored, sssd will not get me a new ticket.
sssd would get new ticket if it was in online mode. But it offline mode.
I would highly recommend to keep time in sync with server and then debug why sssd was in offline mode. Or why it went to offline mode.
With 1.15 you can use sssctl e.g.
I did run sssctl domain-status infinera.com and it came back with: Unable to get online status [3]: Communication error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. Check that SSSD is running and the InfoPipe responder is enabled. Make sure 'ifp' is listed in the 'services' option in sssd.conf. Unable to get online status
I then just added 'ifp' to 'services' and restarted sssd and now it works: sssctl domain-status infinera.com Online status: Online
Active servers: AD Global Catalog: not connected AD Domain Controller: se-dc01.infinera.com .....
Could the problem I saw be related to not having ifp in services ? I will check again when the ticket expires again.
ifp service does not have any effect on ticket renewal.
it is just required by sssctl
LS
sssd-users@lists.fedorahosted.org
-
Jakub Hrozek -
Joakim Tjernlund -
Lukas Slebodnik