On Fri, Feb 10, 2017 at 02:23:24PM -0500, Michael Smith wrote:
On Tue, Feb 7, 2017 at 9:31 AM, Michael Smith
<michael(a)hurts.ca> wrote:
> On Tue, Feb 7, 2017 at 7:55 AM, Sumit Bose <sbose(a)redhat.com> wrote:
>
>> On Tue, Feb 07, 2017 at 12:25:38PM +0100, Lukas Slebodnik wrote:
>> > On (06/02/17 20:25), Jakub Hrozek wrote:
>> > >On Sun, Feb 05, 2017 at 03:17:28AM -0000, michael(a)hurts.ca wrote:
>> > >> Hi,
>> > >>
>> > >> I'm in an environment with several AD sites, each with a DC.
When
>> remote sites' DCs are unreachable because of a VPN outage, I'm not able
to
>> complete password authentication with sudo.
>> > >>
>> > >> Does sssd_krb5_locator_plugin.so work with sssd-ad?
>> > >> Do I need to put anything in krb5.conf to activate it?
>> > >
>> > >No, should be automatic. Does the file the locator plugin writes
>> > >(/var/lib/sss/pubconf/kdcinfo.$REALM contain an address from the right
>> > >DC?
>>
>
> > There is an implicit assumption that the directory /var/lib/sss/pubconf/
>> > is included in krb5.conf. Otherwise it would not work.
>
> It is /var/lib/sss/pubconf/krb5.include.d/ which should be included in
>> /etc/krb5.conf.
>
>
I've changed my krb5.conf to:
includedir /var/lib/sss/pubconf/krb5.include.d
[libdefaults]
default_realm = MY.DOMAIN.HERE
kdc_timesync = 1
forwardable = false
proxiable = false
# Always use TCP
udp_preference_limit = 1
But when I enter my password with sudo, I can see in krb5_child.log that
it's cycling through all the DCs twice, first for UDP and then for TCP. So
it's ignoring the locator information and the udp_preference_limit as well.
I'm on Ubuntu 16.04 LTS, with sssd 1.13.4 and libkrb5-3 1.13.2.
/var/lib/sss/pubconf/kdcinfo.MYDOMAIN is pointing to the correct IP.
In /var/lib/sss/pubconf/krb5.include.d/localauth_plugin I see:
[plugins]
localauth = {
module =
sssd:/usr/lib/x86_64-linux-gnu/sssd/modules/sssd_krb5_localauth_plugin.so
enable_only = sssd
}
Below is the krb5_child.log. I was using an iptables rule to block access
to remote DCs for testing - that's where the "operation not permitted"
errors are coming from.
Thanks,
Mike
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [main] (0x0400):
krb5_child started.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [unpack_buffer]
(0x1000): total buffer size: [172]
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1244801137] gid [1244800513] validate [true]
enterprise principal [true] offline [false] UPN [myuser(a)MY.DOMAIN]
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [unpack_buffer]
(0x0100): ccname: [FILE:/tmp/krb5cc_1244801137_XXXXXX] old_ccname:
[FILE:/tmp/krb5cc_1244801137_OG42mb] keytab: [/etc/krb5.keytab]
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [check_use_fast]
(0x0100): Not using FAST.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [switch_creds]
(0x0200): Switch user to [1244801137][1244800513].
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [switch_creds]
(0x0200): Switch user to [0][0].
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[k5c_check_old_ccache] (0x4000): Ccache_file is
[FILE:/tmp/krb5cc_1244801137_OG42mb] and is active and TGT is valid.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [become_user]
(0x0200): Trying to become user [1244801137][1244800513].
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [main] (0x2000):
Running as [1244801137][1244800513].
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [k5c_setup] (0x2000):
Running as [1244801137][1244800513].
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME]
from environment.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [main] (0x0400): Will
perform online auth
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]] [get_and_save_tgt]
(0x0400): Attempting kinit for realm [MY.DOMAIN]
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.823528: Getting
initial credentials for myuser\@MY.DOMAIN(a)MY.DOMAIN
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.823600: Sending
request (195 bytes) to MY.DOMAIN
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.824295: Resolving
hostname remotedc2.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.824903: Sending
initial UDP request to dgram 100.100.100.100:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.824932: UDP error
sending to dgram 100.100.100.100:88: 1/Operation not permitted
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.824952: Resolving
hostname remotedc1.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825262: Sending
initial UDP request to dgram 50.50.50.50:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825283: UDP error
sending to dgram 50.50.50.50:88: 1/Operation not permitted
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825292: Resolving
hostname remotedc3.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825564: Sending
initial UDP request to dgram 150.150.150.150:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825584: UDP error
sending to dgram 150.150.150.150:88: 1/Operation not permitted
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825593: Resolving
hostname localdc.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.825839: Sending
initial UDP request to dgram 200.200.200.200:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.826367: Received
answer (200 bytes) from dgram 200.200.200.200:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.826621: Response was
not from master KDC
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.826649: Received
error from KDC: -1765328359/Additional pre-authentication required
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.826672: Processing
preauth types: 16, 15, 19, 2
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.826687: Selected
etype info: etype aes256-cts, salt "MY.DOMAINmyuser", params ""
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.833758: AS key
obtained for encrypted timestamp: aes256-cts/9809
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.833799: Encrypted
timestamp (for 1486753194.964234): plain
301AA011180F32303137303231303138353935345AA10502030EB68A, encrypted
A4A9E63C4B9EF4B2F46C230C470FEB690473474C64D59576FA4E62021DB59F30764FC04A8FF134E27460C88065B33C042C99C6D08631E892
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.833812: Preauth
module encrypted_timestamp (2) (real) returned: 0/Success
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.833820: Produced
preauth for next request: 2
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.833838: Sending
request (275 bytes) to MY.DOMAIN
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834351: Resolving
hostname remotedc1.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834643: Sending
initial UDP request to dgram 50.50.50.50:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834664: UDP error
sending to dgram 50.50.50.50:88: 1/Operation not permitted
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834673: Resolving
hostname remotedc3.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834916: Sending
initial UDP request to dgram 150.150.150.150:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834942: UDP error
sending to dgram 150.150.150.150:88: 1/Operation not permitted
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.834952: Resolving
hostname localdc.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.835219: Sending
initial UDP request to dgram 200.200.200.200:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.835922: Received
answer (104 bytes) from dgram 200.200.200.200:88
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836197: Response was
not from master KDC
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836228: Received
error from KDC: -1765328332/Response too big for UDP, retry with TCP
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836237: Request or
response is too big for UDP; retrying with TCP
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836245: Sending
request (275 bytes) to MY.DOMAIN (tcp only)
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836515: Resolving
hostname remotedc2.my.domain.
(Fri Feb 10 18:59:54 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753194.836811: Initiating
TCP connection to stream 100.100.100.100:88
(Fri Feb 10 18:59:55 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753195.837914: Resolving
hostname remotedc1.my.domain.
(Fri Feb 10 18:59:55 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753195.838513: Initiating
TCP connection to stream 50.50.50.50:88
(Fri Feb 10 18:59:56 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753196.839625: Resolving
hostname remotedc3.my.domain.
(Fri Feb 10 18:59:56 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753196.840188: Initiating
TCP connection to stream 150.150.150.150:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.841299: Resolving
hostname localdc.my.domain.
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.841850: Initiating
TCP connection to stream 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.842236: Sending TCP
request to stream 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843071: Received
answer (1679 bytes) from stream 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843087: Terminating
TCP connection to stream 100.100.100.100:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843102: Terminating
TCP connection to stream 50.50.50.50:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843114: Terminating
TCP connection to stream 150.150.150.150:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843125: Terminating
TCP connection to stream 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843405: Response was
not from master KDC
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843441: Processing
preauth types: 19
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843467: Selected
etype info: etype aes256-cts, salt "MY.DOMAINmyuser", params ""
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843478: Produced
preauth for next request: (empty)
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843490: AS key
determined by preauth: aes256-cts/9809
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843538: Decrypted AS
reply; session key is: aes256-cts/A285
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843558: FAST
negotiation: unavailable
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_krb5_expire_callback_func] (0x2000): exp_time: [5191955]
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]] [validate_tgt]
(0x2000): Found keytab entry with the realm of the credential.
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843623: Retrieving
MYHOST$(a)MY.DOMAIN from MEMORY:/etc/krb5.keytab (vno 0, enctype 0) with
result: 0/Success
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843632: Resolving
unique ccache of type MEMORY
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843646: Initializing
MEMORY:E7fvYIM with default princ myuser(a)MY.DOMAIN
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843655: Storing
myuser(a)MY.DOMAIN -> krbtgt/MY.DOMAIN(a)MY.DOMAIN in MEMORY:E7fvYIM
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843670: Getting
credentials myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN using ccache
MEMORY:E7fvYIM
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843691: Retrieving
myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN from MEMORY:E7fvYIM with result:
-1765328243/Matching credential not found
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843706: Retrieving
myuser(a)MY.DOMAIN -> krbtgt/MY.DOMAIN(a)MY.DOMAIN from MEMORY:E7fvYIM with
result: 0/Success
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843715: Starting with
TGT for client realm: myuser(a)MY.DOMAIN -> krbtgt/MY.DOMAIN(a)MY.DOMAIN
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843723: Requesting
tickets for MYHOST$(a)MY.DOMAIN, referrals on
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843740: Generated
subkey for TGS request: aes256-cts/3E51
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843773: etypes
requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac,
camellia128-cts, camellia256-cts
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843821: Encoding
request body and padata into FAST request
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.843866: Sending
request (1798 bytes) to MY.DOMAIN
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.844377: Resolving
hostname remotedc3.my.domain.
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.844786: Sending
initial UDP request to dgram 150.150.150.150:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.844820: UDP error
sending to dgram 150.150.150.150:88: 1/Operation not permitted
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.844837: Resolving
hostname localdc.my.domain.
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.845217: Sending
initial UDP request to dgram 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846275: Received
answer (319 bytes) from dgram 200.200.200.200:88
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846526: Response was
not from master KDC
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846545: Decoding FAST
response
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846572: Request or
response is too big for UDP; retrying with TCP
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846590: Sending
request (1798 bytes) to MY.DOMAIN (tcp only)
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.846836: Resolving
hostname remotedc3.my.domain.
(Fri Feb 10 18:59:57 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753197.847100: Initiating
TCP connection to stream 150.150.150.150:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.848203: Resolving
hostname localdc.my.domain.
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.848800: Initiating
TCP connection to stream 200.200.200.200:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.849046: Sending TCP
request to stream 200.200.200.200:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850162: Received
answer (1778 bytes) from stream 200.200.200.200:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850179: Terminating
TCP connection to stream 150.150.150.150:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850193: Terminating
TCP connection to stream 200.200.200.200:88
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850478: Response was
not from master KDC
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850510: Decoding FAST
response
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850585: FAST reply
key: aes256-cts/0D7C
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850617: TGS reply is
for myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN with session key aes256-cts/F830
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850638: TGS request
result: 0/Success
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850646: Received
creds for desired service MYHOST$(a)MY.DOMAIN
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850657: Storing
myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN in MEMORY:E7fvYIM
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850685: Creating
authenticator for myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN, seqnum 0, subkey
(null), session key aes256-cts/F830
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850747: Retrieving
MYHOST$(a)MY.DOMAIN from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts)
with result: 0/Success
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850789: Decrypted
AP-REQ with specified server principal MYHOST$(a)MY.DOMAIN: aes256-cts/B519
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.850800: AP-REQ
ticket: myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN, session key aes256-cts/F830
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851015: Negotiated
enctype based on authenticator: aes256-cts
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851036: Initializing
MEMORY:rd_req2 with default princ myuser(a)MY.DOMAIN
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851047: Storing
myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN in MEMORY:rd_req2
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851061: Destroying
ccache MEMORY:E7fvYIM
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [validate_tgt]
(0x0400): TGT verified using key for [MYHOST$(a)MY.DOMAIN].
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851087: Retrieving
myuser(a)MY.DOMAIN -> MYHOST$(a)MY.DOMAIN from MEMORY:rd_req2 with result:
0/Success
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851135: Retrieving
MYHOST$(a)MY.DOMAIN from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts)
with result: 0/Success
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [sss_send_pac]
(0x0040): sss_pac_make_request failed [-1][2].
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [validate_tgt]
(0x0040): sss_send_pac failed, group membership for user with principal
[myuser\@MY.DOMAIN(a)MY.DOMAIN] might not be correct.
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_child_krb5_trace_cb] (0x4000): [4246] 1486753198.851194: Destroying
ccache MEMORY:rd_req2
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_get_ccache_name_for_principal] (0x4000): Location:
[FILE:/tmp/krb5cc_1244801137_OG42mb]
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[sss_get_ccache_name_for_principal] (0x4000): tmp_ccname:
[FILE:/tmp/krb5cc_1244801137_OG42mb]
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [create_ccache]
(0x4000): Initializing ccache of type [FILE]
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [create_ccache]
(0x4000): returning: 0
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[safe_remove_old_ccache_file] (0x0400): New and old ccache file are the
same, none will be deleted.
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [k5c_send_data]
(0x0200): Received error code 0
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]]
[pack_response_packet] (0x2000): response packet size: [148]
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [k5c_send_data]
(0x4000): Response sent.
(Fri Feb 10 18:59:58 2017) [[sssd[krb5_child[4246]]]] [main] (0x0400):
krb5_child completed successfully
Could you test the same with KRB5_TRACE=/dev/stderr kinit and also perhaps
with strace kinit to see if the locator file is opened at all and there
are e.g. no permission errors while SSSD is opening the kdcinfo file?