Hello,
some new information. We can reproduce timeout problems on all
environments we tested. One special think is, if we test with an centos
7 client, we have no problems. All other clients (Debian 8/9, Ubuntu
16.04, Centos 6) runs in timeout. It’s seems we have some trouble with
kerberos. I run kinit on a Debian 9 machine without first freeipa server:
|date; KRB5_TRACE=/dev/stderr kinit -k -t /etc/krb5.keytab
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com; date Fr 1. Sep
12:12:01 CEST 2017 [3322] 1504260721.586024: Getting initial credentials
for host/ipa-lx-test-debian9.ipa.example....@ipa.example.com [3322]
1504260721.586884: Looked up etypes in keytab: aes256-cts, aes128-cts,
aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac [3322]
1504260721.587369: Sending request (218 bytes) to IPA.EXAMPLE.COM [3322]
1504260736.605610: Resolving hostname ipa-lx-test-02.ipa.example.com.
[3322] 1504260741.613421: Sending initial UDP request to dgram
<ip_second_freepa_server>:88 [3322] 1504260741.620190: Received answer
(346 bytes) from dgram <ip_second_freepa_server>:88 [3322]
1504260751.629540: Response was from master KDC [3322]
1504260751.630209: Received error from KDC: -1765328359/zusätzlich
Vorauthentifizierung erforderlich [3322] 1504260751.630465: Processing
preauth types: 136, 19, 2, 133 [3322] 1504260751.630491: Selected etype
info: etype aes256-cts, salt
"IPA.EXAMPLE.COMhostipa-lx-test-debian9.ipa.example.com", params ""
[3322] 1504260751.630519: Received cookie: MIT [3322] 1504260751.630793:
Retrieving host/ipa-lx-test-debian9.ipa.example....@ipa.example.com from
FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
[3322] 1504260751.630840: AS key obtained for encrypted timestamp:
aes256-cts/6BAE [3322] 1504260751.630953: Encrypted timestamp (for
1504260741.619515): plain
301AA011180F32303137303930313130313232315AA10502030973FB, encrypted
159D40A2802FF0B5863C075284E3D5086DFF4CF24951374647E501ECA2F2D09230
C57880876C2E55209D23B678D12D54A464D52130546708 [3322] 1504260751.631066:
Preauth module encrypted_timestamp (2) (real) returned: 0/Success [3322]
1504260751.631084: Produced preauth for next request: 133, 2 [3322]
1504260751.631125: Sending request (313 bytes) to IPA.EXAMPLE.COM [3322]
1504260766.647110: Resolving hostname ipa-lx-test-01.ipa.example.com.
[3322] 1504260771.653349: Sending initial UDP request to dgram
<ip_first_freepa_server>:88 [3322] 1504260772.654458: Resolving hostname
ipa-lx-test-02.ipa.example.com. [3322] 1504260777.660742: Sending
initial UDP request to dgram <ip_second_freepa_server>:88 [3322]
1504260777.710507: Received answer (853 bytes) from dgram
<ip_second_freepa_server>:88 [3322] 1504260787.720438: Response was from
master KDC [3322] 1504260787.720549: Processing preauth types: 19 [3322]
1504260787.720571: Selected etype info: etype aes256-cts, salt
"IPA.EXAMPLE.COMhostipa-lx-test-debian9.ipa.example.com", params ""
[3322] 1504260787.720600: Produced preauth for next request: (empty)
[3322] 1504260787.720638: AS key determined by preauth: aes256-cts/6BAE
[3322] 1504260787.720752: Decrypted AS reply; session key is:
aes256-cts/AD23 [3322] 1504260787.720793: FAST negotiation: available
[3322] 1504260787.720839: Initializing
KEYRING:persistent:0:krb_ccache_y1364Hz with default princ
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com [3322]
1504260787.720928: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krbtgt/ipa.example....@ipa.example.com in
KEYRING:persistent:0:krb_ccache_y1364Hz [3322] 1504260787.721029:
Storing config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/ipa.example....@ipa.example.com: fast_avail: yes [3322]
1504260787.721070: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krb5_ccache_conf_data/fast_avail/krbtgt\/IPA.EXAMPLE.COM\@IPA.EXAMPLE.COM@X-CACHECONF:
in KEYRING:persistent:0:kr b_ccache_y1364Hz [3322] 1504260787.721153:
Storing config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/ipa.example....@ipa.example.com: pa_type: 2 [3322]
1504260787.721184: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krb5_ccache_conf_data/pa_type/krbtgt\/IPA.EXAMPLE.COM\@IPA.EXAMPLE.COM@X-CACHECONF:
in KEYRING:persistent:0:krb_c cache_y1364Hz Fr 1. Sep 12:13:07 CEST 2017 |
And than with first ipa server:
|date; KRB5_TRACE=/dev/stderr kinit -k -t /etc/krb5.keytab
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com; date Fr 1. Sep
12:52:29 CEST 2017 [3367] 1504263149.757320: Getting initial credentials
for host/ipa-lx-test-debian9.ipa.example....@ipa.example.com [3367]
1504263149.758392: Looked up etypes in keytab: aes256-cts, aes128-cts,
aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac [3367]
1504263149.758871: Sending request (218 bytes) to IPA.EXAMPLE.COM [3367]
1504263149.761654: Resolving hostname ipa-lx-test-01.ipa.example.com.
[3367] 1504263149.763472: Sending initial UDP request to dgram
<ip_first_freepa_server>:88 [3367] 1504263149.768906: Received answer
(346 bytes) from dgram <ip_first_freepa_server>:88 [3367]
1504263149.770289: Response was from master KDC [3367]
1504263149.770598: Received error from KDC: -1765328359/zusätzlich
Vorauthentifizierung erforderlich [3367] 1504263149.770961: Processing
preauth types: 136, 19, 2, 133 [3367] 1504263149.770983: Selected etype
info: etype aes256-cts, salt
"IPA.EXAMPLE.COMhostipa-lx-test-debian9.ipa.example.com", params ""
[3367] 1504263149.771230: Received cookie: MIT [3367] 1504263149.771843:
Retrieving host/ipa-lx-test-debian9.ipa.example....@ipa.example.com from
FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
[3367] 1504263149.772284: AS key obtained for encrypted timestamp:
aes256-cts/6BAE [3367] 1504263149.772629: Encrypted timestamp (for
1504263149.854417): plain
301AA011180F32303137303930313130353232395AA10502030D0991, encrypted
321783A9E5E7B15D62F61B9D0177E7284193EE6AE531CDD730E021E149A4C1AD4C
1970D2DC5C5A608CD8B1CB24E1737BA916BDF62B73330B [3367] 1504263149.773120:
Preauth module encrypted_timestamp (2) (real) returned: 0/Success [3367]
1504263149.773135: Produced preauth for next request: 133, 2 [3367]
1504263149.773601: Sending request (313 bytes) to IPA.EXAMPLE.COM [3367]
1504263149.775373: Resolving hostname ipa-lx-test-02.ipa.example.com.
[3367] 1504263149.776259: Sending initial UDP request to dgram
<ip_second_freepa_server>:88 [3367] 1504263149.831817: Received answer
(853 bytes) from dgram <ip_second_freepa_server>:88 [3367]
1504263149.833719: Response was from master KDC [3367]
1504263149.834058: Processing preauth types: 19 [3367]
1504263149.834077: Selected etype info: etype aes256-cts, salt
"IPA.EXAMPLE.COMhostipa-lx-test-debian9.ipa.example.com", params ""
[3367] 1504263149.834326: Produced preauth for next request: (empty)
[3367] 1504263149.834868: AS key determined by preauth: aes256-cts/6BAE
[3367] 1504263149.835207: Decrypted AS reply; session key is:
aes256-cts/5B05 [3367] 1504263149.835510: FAST negotiation: available
[3367] 1504263149.835780: Initializing
KEYRING:persistent:0:krb_ccache_y1364Hz with default princ
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com [3367]
1504263149.836208: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krbtgt/ipa.example....@ipa.example.com in
KEYRING:persistent:0:krb_ccache_y1364Hz [3367] 1504263149.836647:
Storing config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/ipa.example....@ipa.example.com: fast_avail: yes [3367]
1504263149.837000: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krb5_ccache_conf_data/fast_avail/krbtgt\/IPA.EXAMPLE.COM\@IPA.EXAMPLE.COM@X-CACHECONF:
in KEYRING:persistent:0:kr b_ccache_y1364Hz [3367] 1504263149.837513:
Storing config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/ipa.example....@ipa.example.com: pa_type: 2 [3367]
1504263149.837836: Storing
host/ipa-lx-test-debian9.ipa.example....@ipa.example.com ->
krb5_ccache_conf_data/pa_type/krbtgt\/IPA.EXAMPLE.COM\@IPA.EXAMPLE.COM@X-CACHECONF:
in KEYRING:persistent:0:krb_c cache_y1364Hz Fr 1. Sep 12:52:29 CEST 2017 |
If we change /etc/resolv.conf that second freeipa server is listed
before first server, we got our ticket as expected:
|date; KRB5_TRACE=/dev/stderr kinit -k -t /etc/krb5.keytab
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com; date Fr 1.
Sep 13:23:26 CEST 2017 [377] 1504265006.312401: Getting initial
credentials for
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com [377]
1504265006.313134: Looked up etypes in keytab: aes256-cts, aes128-cts,
aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac [377]
1504265006.313281: Sending request (218 bytes) to NBG.WEBTREKK.COM [377]
1504265006.315715: Resolving hostname ipa-lx-test-02.nbg.webtrekk.com.
[377] 1504265006.317085: Sending initial UDP request to dgram
172.25.5.158:88 [377] 1504265006.321621: Received answer (346 bytes)
from dgram 172.25.5.158:88 [377] 1504265006.322942: Response was from
master KDC [377] 1504265006.323002: Received error from KDC:
-1765328359/zusätzlich Vorauthentifizierung erforderlich [377]
1504265006.323070: Processing preauth types: 136, 19, 2, 133 [377]
1504265006.323091: Selected etype info: etype aes256-cts, salt
"NBG.WEBTREKK.COMhostipa-lx-test-debian9.nbg.webtrekk.com", params ""
[377] 1504265006.323108: Received cookie: MIT [377] 1504265006.323286:
Retrieving host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com
from FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result:
0/Success [377] 1504265006.323324: AS key obtained for encrypted
timestamp: aes256-cts/6BAE [377] 1504265006.323424: Encrypted timestamp
(for 1504265006.319960): plain
301AA011180F32303137303930313131323332365AA105020304E1D8, encrypted
98F9D8555750DAFCB63346659ED490F7731E94C675EF45D643669E8107950B404CCF6DA4EA78D1F9CBDDFD896CAEDA11809DA855647D4C27
[377] 1504265006.323452: Preauth module encrypted_timestamp (2) (real)
returned: 0/Success [377] 1504265006.323467: Produced preauth for next
request: 133, 2 [377] 1504265006.323499: Sending request (313 bytes) to
NBG.WEBTREKK.COM [377] 1504265006.324868: Resolving hostname
ipa-lx-test-01.nbg.webtrekk.com. [377] 1504265006.325426: Sending
initial UDP request to dgram 172.25.5.153:88 [377] 1504265007.326527:
Resolving hostname ipa-lx-test-02.nbg.webtrekk.com. [377]
1504265007.327750: Sending initial UDP request to dgram 172.25.5.158:88
[377] 1504265007.411975: Received answer (853 bytes) from dgram
172.25.5.158:88 [377] 1504265007.413248: Response was from master KDC
[377] 1504265007.413311: Processing preauth types: 19 [377]
1504265007.413335: Selected etype info: etype aes256-cts, salt
"NBG.WEBTREKK.COMhostipa-lx-test-debian9.nbg.webtrekk.com", params ""
[377] 1504265007.413353: Produced preauth for next request: (empty)
[377] 1504265007.413374: AS key determined by preauth: aes256-cts/6BAE
[377] 1504265007.413480: Decrypted AS reply; session key is:
aes256-cts/7D39 [377] 1504265007.413523: FAST negotiation: available
[377] 1504265007.413570: Initializing
KEYRING:persistent:0:krb_ccache_y1364Hz with default princ
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com [377]
1504265007.413655: Storing
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com ->
krbtgt/nbg.webtrekk....@nbg.webtrekk.com in
KEYRING:persistent:0:krb_ccache_y1364Hz [377] 1504265007.413759: Storing
config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/nbg.webtrekk....@nbg.webtrekk.com: fast_avail: yes [377]
1504265007.413800: Storing
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com ->
krb5_ccache_conf_data/fast_avail/krbtgt\/NBG.WEBTREKK.COM\@NBG.WEBTREKK.COM@X-CACHECONF:
in KEYRING:persistent:0:krb_ccache_y1364Hz [377] 1504265007.413886:
Storing config in KEYRING:persistent:0:krb_ccache_y1364Hz for
krbtgt/nbg.webtrekk....@nbg.webtrekk.com: pa_type: 2 [377]
1504265007.413918: Storing
host/ipa-lx-test-debian9.nbg.webtrekk....@nbg.webtrekk.com ->
krb5_ccache_conf_data/pa_type/krbtgt\/NBG.WEBTREKK.COM\@NBG.WEBTREKK.COM@X-CACHECONF:
in KEYRING:persistent:0:krb_ccache_y1364Hz Fr 1. Sep 13:23:27 CEST 2017 |
Is this a normal behavior ? How can we work with this ?
Michael
Am 31.08.2017 um 09:32 schrieb Michael Gusek via FreeIPA-users:
> Hi,
>
> just for info. We restart our setup on an other stage in our dc with
> same result, we run in timeouts if first installed ipa server not
> available. So we give it a try in a complete different environment,
> with successfully failover. It seem's we have a problem in our dc and
> we will have a deeper look on our environment.
>
> Thanks,
>
> Michael
>
>
> Am 24.08.2017 um 21:12 schrieb Jakub Hrozek via FreeIPA-users:
>> On Thu, Aug 24, 2017 at 10:12:55AM +0200, Michael Gusek via FreeIPA-users
>> wrote:
>>> Hello Jakub,
>>>
>>> here the first lines of ldap_child.log
>>>
>>> |(Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [main] (0x0400):
>>> ldap_child started. (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [main] (0x2000): context initialized (Wed Aug
>>> 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [unpack_buffer] (0x1000):
>>> total buffer size: 81 (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [unpack_buffer] (0x1000): realm_str size: 16
>>> (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [unpack_buffer]
>>> (0x1000): got realm_str: IPA.EXAMPLE.COM (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [unpack_buffer] (0x1000): princ_str size: 41
>>> (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [unpack_buffer]
>>> (0x1000): got princ_str: host/ipa-lx-test-debian9.ípa.example.com (Wed
>>> Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [unpack_buffer]
>>> (0x1000): keytab_name size: 0 (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [unpack_buffer] (0x1000): lifetime: 86400
>>> (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [unpack_buffer]
>>> (0x0200): Will run as [0][0]. (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [privileged_krb5_setup] (0x2000): Kerberos
>>> context initialized (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [main] (0x2000): Kerberos context initialized
>>> (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [become_user]
>>> (0x0200): Trying to become user [0][0]. (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [become_user] (0x0200): Already user [0].
>>> (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]] [main] (0x2000):
>>> Running as [0][0]. (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]]
>>> [main] (0x2000): getting TGT sync (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [ldap_child_get_tgt_sync] (0x2000): got
>>> realm_name: [IPA.EXAMPLE.COM] (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [ldap_child_get_tgt_sync] (0x0100): Principal
>>> name is: [host/ipa-lx-test-debian9.ípa.example....@ipa.example.com] (Wed
>>> Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]]
>>> [ldap_child_get_tgt_sync] (0x0100): Using keytab
>>> [MEMORY:/etc/krb5.keytab] (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [ldap_child_get_tgt_sync] (0x0100): Will
>>> canonicalize principals (Wed Aug 23 16:07:11 2017)
>>> [[sssd[ldap_child[2104]]]] [sss_child_krb5_trace_cb] (0x4000): [2104]
>>> 1503497231.122092: Getting initial credentials for
>>> host/ipa-lx-test-debian9.ípa.example....@ipa.example.com (Wed Aug 23
>>> 16:07:11 2017) [[sssd[ldap_child[2104]]]] [sss_child_krb5_trace_cb]
>>> (0x4000): [2104] 1503497231.122313: Looked up etypes in keytab:
>>> aes256-cts, aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1,
>>> rc4-hmac (Wed Aug 23 16:07:11 2017) [[sssd[ldap_child[2104]]]]
>>> [sss_child_krb5_trace_cb] (0x4000): [2104] 1503497231.122451: Sending
>>> request (218 bytes) to IPA.EXAMPLE.COM (Wed Aug 23 16:07:17 2017)
>>> [[sssd[ldap_child[2104]]]] [sig_term_handler] (0x0010): Received signal
>>> [Terminated] [15], shutting down (Wed Aug 23 16:07:17 2017)
>>> [[sssd[ldap_child[2104]]]] [sig_term_handler] (0x0010): Unlink file
>>> [/var/lib/sss/db/ccache_IPA.EXAMPLE.COM_TmKHkD] (Wed Aug 23 16:07:17
>>> 2017) [[sssd[ldap_child[2105]]]] [main] (0x0400): ldap_child started.
>>> (Wed Aug 23 16:07:17 2017) [[sssd[ldap_child[2105]]]] [main] (0x2000):
>>> context initialized |
>>>
>>> We connect to IPA.EXAMPLE.COM, this is not helpfull. You can see, there
>>> is a delay of 5 seconds. Later in this file, you can see, we try to
>>> connect to second server ipa-lx-test-02.ípa.example.com.
>> Right, sssd says it does, but I really wonder why the ldap_child
>> timeouts even in that case. Are there any log entries in the
>> ipa-lx-test-02.ípa.example.com's log files around the time sssd connects
>> to it?
>>
>> And also -- could you run a simple tcpdump (tcpdump -i eth1 -x "port
>> 88 or port 53") to see what hosts does sssd talk to and what hosts does
>> it discover?
>>
>> What I'm wondering is -- does SSSD really talk to the right server at
>> that time or does it keep trying the bad one even if it should be trying
>> the one that is up?
>>
>> By the way, I'm suprised that the failover doesn't work for you. This is a
>> quite basic feature that had been developed years ago. Can you also specify
>> exactly how you bring one of the IDM servers down? Do you power it off,
>> run ipactl stop, ...?
>>
>>> |(Wed Aug 23 16:10:14 2017) [[sssd[ldap_child[2129]]]]
>>> [sss_child_krb5_trace_cb] (0x4000): [2129] 1503497414.357486: Getting
>>> initial credentials for
>>> host/ipa-lx-test-debian9.ípa.example....@ipa.example.com (Wed Aug 23
>>> 16:10:14 2017) [[sssd[ldap_child[2129]]]] [sss_child_krb5_trace_cb]
>>> (0x4000): [2129] 1503497414.357715: Looked up etypes in keytab:
>>> aes256-cts, aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1,
>>> rc4-hmac (Wed Aug 23 16:10:14 2017) [[sssd[ldap_child[2129]]]]
>>> [sss_child_krb5_trace_cb] (0x4000): [2129] 1503497414.357842: Sending
>>> request (218 bytes) to IPA.EXAMPLE.COM (Wed Aug 23 16:10:14 2017)
>>> [[sssd[ldap_child[2129]]]] [sss_child_krb5_trace_cb] (0x4000): [2129]
>>> 1503497414.360574: Resolving hostname ipa-lx-test-02.ípa.example.com.
>>> (Wed Aug 23 16:10:14 2017) [[sssd[ldap_child[2129]]]]
>>> [sss_child_krb5_trace_cb] (0x4000): [2129] 1503497414.362141: Sending
>>> initial UDP request to dgram <ip_of_ipa-lx-test-02>:88 (Wed Aug 23
>>> 16:10:14 2017) [[sssd[ldap_child[2129]]]] [sss_child_krb5_trace_cb]
>>> (0x4000): [2129] 1503497414.367725: Received answer (346 bytes) from
>>> dgram <ip_of_ipa-lx-test-02>:88 (Wed Aug 23 16:10:19 2017)
>>> [[sssd[ldap_child[2129]]]] [sss_child_krb5_trace_cb] (0x4000): [2129]
>>> 1503497419.374601: Response was from master KDC |
>>>
>>> I think this was my test with ‘kinit ad...@ipa.example.com’. You can
>>> find whole log file attached. From my point of view, failover to second
>>> KDC is not fast enough and we should set some timeouts in sssd.conf or
>>> krb5.conf ?
>> Well, kinit doesn't talk to sssd..
>>
>> sssd only has interfaces towards the NSS and PAM subsystems, so kinit
>> talks straight to libkrb5. What /KDCs/ does kinit talk to depends on
>> libkrb5 configuration. In your case, it doesn't contain any KDCs, so
>> it's either what SSSD tells libkrb5 to look at (through a kdcinfo file
>> interface) DNS (because dns_lookup_kdc = true) in this order. And the
>> kdcinfo files should not be generated unless sssd can switch to the
>> 'online' mode here.
>>
>>> krb5.conf from ipa-lx-test-debian9:
>>>
>>> |#File modified by ipa-client-install includedir
>>> /var/lib/sss/pubconf/krb5.include.d/ [libdefaults] default_realm =
>>> IPA.EXAMPLE.COM dns_lookup_realm = true dns_lookup_kdc = true rdns =
>>> false ticket_lifetime = 24h forwardable = yes default_ccache_name =
>>> KEYRING:persistent:%{uid} [realms] IPA.EXAMPLE.COM = { pkinit_anchors =
>>> FILE:/etc/ipa/ca.crt } [domain_realm] .ipa.example.com = IPA.EXAMPLE.COM
>>> ipa.example.com = IPA.EXAMPLE.COM |
>>>
>>> Regards,
>>>
>>> Michael
>>>
>>> Am 23.08.2017 um 22:20 schrieb Jakub Hrozek via FreeIPA-users:
>>>
>>>> On Wed, Aug 23, 2017 at 05:13:13PM +0200, Michael Gusek via FreeIPA-users
>>>> wrote:
>>>>> Hi,
>>>>>
>>>>> we are testing a FreeIPA trust to an Active Directory. Trust itself
>>>>> works, we are happy. Now we tested a failure on FreeIPA site. We have
>>>>> two instances, both with same roles. If we poweroff first installed
>>>>> server, and clean sssd caches with restart of sssd on client side , sssd
>>>>> service can’t establish a connection to second instance.
>>>>>
>>>>> ipa-lx-test-01.ipa.example.com is the first installed FreeIPA with
>>>>> ipa-server-4.4.0-14.el7.centos.7.x86_64 on latest CentOS7
>>>>> ipa-lx-test-02.ipa.example.com is the second installed FreeIPA with
>>>>> ipa-server-4.4.0-14.el7.centos.7.x86_64 on latest CentOS7
>>>>> ipa-lx-test-debian9.ipa.example.com is a latest Debian 9.1 with sssd
>>>>> 1.15.0-3
>>>>>
>>>>> For deeper inspection full log is attached. In logs we found something
>>>>> like this:
>>>> OK, so as you say communication with the KDC failed:
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [be_resolve_server_process] (0x0200): Found address for server
>>>> ipa-lx-test-02.ipa.example.com: [x.x.x.x] TTL 1200
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
>>>>
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [create_tgt_req_send_buffer] (0x0400): buffer size: 81
>>>>
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [child_handler_setup] (0x2000): Setting up signal handler up for pid
>>>> [2104]
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [child_handler_setup] (0x2000): Signal handler set up for pid [2104]
>>>>
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
>>>>
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [sdap_process_result] (0x2000): Trace: sh[0x558252c35750], connected[1],
>>>> ops[(nil)], ldap[0x558252c130c0]
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [sdap_process_result] (0x2000): Trace: end of ldap_result list
>>>>
>>>>
>>>> (Wed Aug 23 16:07:11 2017) [sssd[be[ipa.example.com]]]
>>>> [write_pipe_handler] (0x0400): All data has been sent!
>>>>
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]]
>>>> [get_tgt_timeout_handler] (0x4000): timeout for sending SIGTERM to tgt
>>>> child [2104] reached.
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]]
>>>> [get_tgt_timeout_handler] (0x0400): Setting 2 seconds timeout for sending
>>>> SIGKILL to tgt child
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]] [read_pipe_handler]
>>>> (0x0400): EOF received, client finished
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]] [child_sig_handler]
>>>> (0x1000): Waiting for child [2104].
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]] [child_sig_handler]
>>>> (0x0020): child [2104] failed with status [7].
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]] [child_callback]
>>>> (0x0020): LDAP child was terminated due to timeout
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]] [sdap_kinit_done]
>>>> (0x0080): Communication with KDC timed out, trying the next one
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]]
>>>> [_be_fo_set_port_status] (0x8000): Setting status: PORT_NOT_WORKING.
>>>> Called from: ../src/providers/ldap/sdap_async_connection.c:
>>>> sdap_kinit_done: 1207
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]]
>>>> [fo_set_port_status] (0x0100): Marking port 389 of server
>>>> 'ipa-lx-test-02.ipa.example.com' as 'not working'
>>>>
>>>> (Wed Aug 23 16:07:17 2017) [sssd[be[ipa.example.com]]]
>>>> [fo_set_port_status] (0x0400): Marking port 389 of duplicate server
>>>> 'ipa-lx-test-02.ipa.example.com' as 'not working'
>>>>
>>>> Could you check in the ldap_child.log which KDC did SSSD try to talk to
>>>> and what takes so long?
>>>> _______________________________________________
>>>> FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
>>>> To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
>>>
>>> --
>>>
>>> ________________________________________________
>>>
>>>
>>> *Michael**Gusek*| System Administrator| Webtrekk GmbH |
>>> *t*+49 30 755 415 302| *f *+49 30 755 415 100 | *w *www.webtrekk.com
>>> <https://www.webtrekk.com/?wt_mc=signature.-.-.-.homepageURL>
>>> Amtsgericht/Local Court Berlin, HRB 93435 B | Geschäftsführer/CEO
>>> Christian Sauer und Wolf Lichtenstein
>>>
>>>
>>> _______________________________________________
>>> FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
>>> To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
>> _______________________________________________
>> FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
>> To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
>
> --
>
> ________________________________________________
>
>
> *Michael**Gusek*| System Administrator| Webtrekk GmbH |
> *t*+49 30 755 415 302| *f *+49 30 755 415 100 | *w *www.webtrekk.com
> <https://www.webtrekk.com/?wt_mc=signature.-.-.-.homepageURL>
> Amtsgericht/Local Court Berlin, HRB 93435 B | Geschäftsführer/CEO
> Christian Sauer und Wolf Lichtenstein
>
>
>
>
> _______________________________________________
> FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
> To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
--
________________________________________________
*Michael**Gusek*| System Administrator| Webtrekk GmbH |
*t*+49 30 755 415 302| *f *+49 30 755 415 100 | *w *www.webtrekk.com
<https://www.webtrekk.com/?wt_mc=signature.-.-.-.homepageURL>
Amtsgericht/Local Court Berlin, HRB 93435 B | Geschäftsführer/CEO
Christian Sauer und Wolf Lichtenstein
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
