Re: [Freeipa-users] sssd doesn't cache, as it seems

[Harald Dunkel]

On 01/20/17 18:42, Simo Sorce wrote:
> 
> Is your server being used for authentication ?
> SSSD, by default, always refreshes user credentials on authentication,
> but you can use the cached_auth_timeout setting to relax this
> requirement in SSSD, and reduce the roundtrips for auth attempts.
> 

I have set both pam_id_timeout and cached_auth_timeout to 30.
No change, still several requests per second for each user.

???
Harri

[domain/example.de]
debug_level = 0x0370
cache_credentials = True
cached_auth_timeout = 30
krb5_store_password_if_offline = True
ipa_domain = example.de
id_provider = ipa
auth_provider = ipa
access_provider = ipa
ldap_tls_cacert = /etc/ipa/ca.crt
ipa_hostname = tisde8i005.ac.example.de
chpass_provider = ipa
ipa_server = _srv_, ipa1.example.de
dns_discovery_domain = example.de
selinux_provider = none

[sssd]
debug_level = 0x0370
services = nss, sudo, pam, ssh
config_file_version = 2
domains = example.de

[nss]
debug_level = 0x0370
homedir_substring = /home

[pam]
pam_id_timeout = 30
debug_level = 0x0370

[sudo]

[autofs]

[ssh]
debug_level = 0x0370

[pac]

[ifp]

-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Sullivan, Daniel [CRI]]

Thank you for responding Lukas.  This is actually a domain controller that 
trusts an AD domain, as far as I know winbindd was never installed specifically 
to fulfill a purpose other than for IPA (the machine was deployed specifically 
for the purpose of being an IPA DC).  Hopefully this sounds reasonable and sane…

And, no, winbind is not configured in nsswitch.

Dan

> On Jan 20, 2017, at 4:48 PM, Lukas Slebodnik  wrote:
> 
> On (20/01/17 20:18), Sullivan, Daniel [CRI] wrote:
>> Sorry to clutter people's inboxes.  I found another piece of what I believe 
>> to be useful information.  When this occurs the following entry also appears 
>> in /var/log/messages.
>> 
>> Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>> 13:54:33.942448,  0] ipa_sam.c:4193(bind_callback_cleanup)
>> Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   kerberos error: 
>> code=-1765328228, message=Cannot contact any KDC for realm 
>> ‘XXX.XXX.UCHICAGO.EDU'
>> Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>> 13:54:33.943497,  0] ../source3/lib/smbldap.c:998(smbldap_connect_system)
>> Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   failed to bind to 
>> server ldapi://%2fvar%2frun%2fslapd-XXX-XXX-UCHICAGO-EDU.socket with 
>> dn="[Anonymous bind]" Error: Local error
>> Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   #011(unknown)
>> Jan 20 13:55:16 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>> 13:55:16.970304,  0] ipa_sam.c:4193(bind_callback_cleanup)
>> Jan 20 13:55:16 xxx.xxx.uchicago.edu winbindd[7090]:   kerberos error: 
>> code=-1765328228, message=Cannot contact any KDC for realm 
>> ‘XXX.XXX.UCHICAGO.EDU'
>> Jan 20 14:00:01 xxx.xxx.uchicago.edu systemd[1]: Created slice user-0.slice.
>> 
> May I ask why you have configure sssd and winbind on the same machine?
> Do you have configured winbind also in /etc/nsswitch.conf?
> 
> LS


-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Lukas Slebodnik]

On (20/01/17 20:18), Sullivan, Daniel [CRI] wrote:
>Sorry to clutter people's inboxes.  I found another piece of what I believe to 
>be useful information.  When this occurs the following entry also appears in 
>/var/log/messages.
>
>Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>13:54:33.942448,  0] ipa_sam.c:4193(bind_callback_cleanup)
>Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   kerberos error: 
>code=-1765328228, message=Cannot contact any KDC for realm 
>‘XXX.XXX.UCHICAGO.EDU'
>Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>13:54:33.943497,  0] ../source3/lib/smbldap.c:998(smbldap_connect_system)
>Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   failed to bind to 
>server ldapi://%2fvar%2frun%2fslapd-XXX-XXX-UCHICAGO-EDU.socket with 
>dn="[Anonymous bind]" Error: Local error
>Jan 20 13:54:33 xxx.xxx.uchicago.edu winbindd[7090]:   #011(unknown)
>Jan 20 13:55:16 xxx.xxx.uchicago.edu winbindd[7090]: [2017/01/20 
>13:55:16.970304,  0] ipa_sam.c:4193(bind_callback_cleanup)
>Jan 20 13:55:16 xxx.xxx.uchicago.edu winbindd[7090]:   kerberos error: 
>code=-1765328228, message=Cannot contact any KDC for realm 
>‘XXX.XXX.UCHICAGO.EDU'
>Jan 20 14:00:01 xxx.xxx.uchicago.edu systemd[1]: Created slice user-0.slice.
>
May I ask why you have configure sssd and winbind on the same machine?
Do you have configured winbind also in /etc/nsswitch.conf?

LS

-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] sssd doesn't cache, as it seems

[Simo Sorce]

On Fri, 2017-01-20 at 18:14 +0100, Harald Dunkel wrote:
> Hi folks,
> 
> I see a pretty large number of ldap requests sent by our git
> server, asking for the same account info again and again.
> Sometimes it asks 20 times per second for the same user info,
> for example.
> 
> Obviously caching doesn't work.

Is your server being used for authentication ?
SSSD, by default, always refreshes user credentials on authentication,
but you can use the cached_auth_timeout setting to relax this
requirement in SSSD, and reduce the roundtrips for auth attempts.

HTH,
Simo.

>  I remember some note in the
> installation guide suggesting to turn of nscd and that sssd
> takes over this job, so I wonder wth? A recent EMail in this
> forum suggested to set selinux_provider = none, but this
> didn't help.
> 
> Ipa server is Centos 7.3, client is on Jessie with sssd 1.13.4.
> 
> 
> sssd.conf is attached, of course. Every helpful comment is highly
> appreciated.
> 
> Harri
> -- 
> Manage your subscription for the Freeipa-users mailing list:
> https://www.redhat.com/mailman/listinfo/freeipa-users
> Go to http://freeipa.org for more info on the project


-- 
Simo Sorce * Red Hat, Inc * New York

-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

[Freeipa-users] sssd doesn't cache, as it seems

[Harald Dunkel]

Hi folks,

I see a pretty large number of ldap requests sent by our git
server, asking for the same account info again and again.
Sometimes it asks 20 times per second for the same user info,
for example.

Obviously caching doesn't work. I remember some note in the
installation guide suggesting to turn of nscd and that sssd
takes over this job, so I wonder wth? A recent EMail in this
forum suggested to set selinux_provider = none, but this
didn't help.

Ipa server is Centos 7.3, client is on Jessie with sssd 1.13.4.


sssd.conf is attached, of course. Every helpful comment is highly
appreciated.

Harri
[domain/example.de]
debug_level = 0x0370
cache_credentials = True
krb5_store_password_if_offline = True
ipa_domain = example.de
id_provider = ipa
auth_provider = ipa
access_provider = ipa
ldap_tls_cacert = /etc/ipa/ca.crt
ipa_hostname = tisde8i005.ac.example.de
chpass_provider = ipa
ipa_server = _srv_, ipa1.example.de
dns_discovery_domain = example.de
selinux_provider = none

[sssd]
debug_level = 0x0370
services = nss, sudo, pam, ssh
config_file_version = 2
domains = example.de

[nss]
debug_level = 0x0370
homedir_substring = /home

[pam]
debug_level = 0x0370

[sudo]

[autofs]

[ssh]
debug_level = 0x0370

[pac]

[ifp]



signature.asc
Description: OpenPGP digital signature
-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Sullivan, Daniel [CRI]]

Sorry I didn’t realize you might want all sssd logs… Working on it.

Dan

> On Jan 20, 2017, at 10:27 AM, Sumit Bose  wrote:
> 
> On Fri, Jan 20, 2017 at 03:41:46PM +, Sullivan, Daniel [CRI] wrote:
>> Hi,
>> 
>> I have some more information on this issue.  I’m tracing it down through the 
>> slapd logs and  I am continuing to struggle; I was hoping that somebody 
>> could possibly help me provided this additional information.
>> 
>> On the domain logs (on the DC), I see an ldap_search_ext operation 155 with 
>> a timeout of 60:
>> 
>> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
>> [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))][cn=Default
>>  Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu].
>> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 155
>> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_add] 
>> (0x2000): New operation 155 timeout 60
>> 
>> Then, on the slapd log for the server, I see the incoming request.  Based on 
>> the result, it looks like the request completes successfully within 1 second:
>> 
>> [20/Jan/2017:08:42:35.179890746 -0600] conn=1518 op=31 SRCH base="cn=Default 
>> Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu" scope=2 
>> filter="(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))" 
>> attrs=ALL
>> [20/Jan/2017:08:42:35.683485674 -0600] conn=1518 op=31 RESULT err=0 tag=101 
>> nentries=0 etime=1 notes=U
>> 
>> Then, subsequently, the domain log (on the DC), I see the same operation 155 
>> timeout (expectedly almost a minute later).
> 
> So it looks like ns-ldap send the response but it never reached SSSD in
> time. Can you send what it happening in the SSSD logs between 08:42:34
> and 08:43:34 (if you prefer you can send it to me directly). Maybe there
> is an operation which blocks SSSD for too long so that it returns too
> late to the main loop to process the response?
> 
> bye,
> Sumit
> 
>> 
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_op_timeout] (0x1000): Issuing timeout for 155
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_op_destructor] (0x1000): Abandoning operation 155
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [generic_ext_search_handler] (0x0040): sdap_get_generic_ext_recv failed 
>> [110]: Connection timed out
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [ipa_get_ad_override_done] (0x0040): ipa_get_ad_override request failed.
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_id_op_destroy] (0x4000): releasing operation connection
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [ipa_initgr_get_overrides_override_done] (0x0040): IPA override lookup 
>> failed: 110
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [ipa_id_get_groups_overrides_done] (0x0040): IPA resolve user groups 
>> overrides failed [110].
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [be_mark_dom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu offline
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [be_mark_subdom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu as 
>> inactive
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [ipa_srv_ad_acct_lookup_done] (0x0040): ipa_get_*_acct request failed: 
>> [110]: Connection timed out.
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [110]: 
>> Connection timed out.
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [sdap_id_op_destroy] (0x4000): releasing operation connection
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [dp_reply_std_set] (0x0080): DP Error is OK on failed request?
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_done] 
>> (0x0400): DP Request [Account #4292]: Request handler finished [0]: Success
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [_dp_req_recv] 
>> (0x0400): DP Request [Account #4292]: Receiving request data.
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [dp_req_reply_list_success] (0x0400): DP Request [Account #4292]: Finished. 
>> Success.
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [dp_req_reply_std] (0x1000): DP Request [Account #4292]: Returning 
>> [Success]: 0,110,Success
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [dp_table_value_destructor] (0x0400): Removing 
>> [0:1:0x0001:1:1::bsdad.uchicago.edu:name=user...@domain.uchicago.edu] from 
>> reply table
>> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
>> [dp_req_destructor] (0x0400): DP Request [Account 

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Sullivan, Daniel [CRI]]

Sumit,

Thank you for taking the time to help me; I know you are very active on 
supporting this project and I am thankful that you are willing to help me 
analyze this data.  As per your request here is the log data from SSSD from the 
time window you specified.  I anonymized the data but used find/replace so AAA 
/BBB/CCC/domain is consistent.

I really appreciate your help.

Thank you,

Dan

(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f5b5c3eec20], connected[1], 
ops[0x7f5b5c3f7ed0], ldap[0x7f5b5c3df9a0]
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg 
set
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_op_destructor] (0x2000): Operation 153 finished
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_get_ad_override_done] (0x4000): No override found with filter 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:AAA))].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_initgr_get_overrides_step] (0x1000): Processing group 1/4
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_initgr_get_overrides_step] (0x1000): Fetching group BBB
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in view 
[Default Trust View] with filter 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:BBB))].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_print_server] 
(0x2000): Searching 10.50.178.21:389
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:BBB))][cn=Default Trust 
View,cn=views,cn=accounts,dc=ipa,dc=cri,dc=uchicago,dc=edu].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 154
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_add] 
(0x2000): New operation 154 timeout 60
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f5b5c3eec20], connected[1], 
ops[0x7f5b5c3f7ed0], ldap[0x7f5b5c3df9a0]
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_result] (0x2000): Trace: end of ldap_result list
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f5b5c3eec20], connected[1], 
ops[0x7f5b5c3f7ed0], ldap[0x7f5b5c3df9a0]
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg 
set
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_op_destructor] (0x2000): Operation 154 finished
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_get_ad_override_done] (0x4000): No override found with filter 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:BBB))].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_initgr_get_overrides_step] (0x1000): Processing group 2/4
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_initgr_get_overrides_step] (0x1000): Fetching group CCC
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in view 
[Default Trust View] with filter 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:CCC))].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_print_server] 
(0x2000): Searching 10.50.178.21:389
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:CCC))][cn=Default Trust 
View,cn=views,cn=accounts,dc=ipa,dc=cri,dc=uchicago,dc=edu].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 155
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_add] 
(0x2000): New operation 155 timeout 60
(Fri Jan 20 08:42:34 2017) 

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Sumit Bose]

On Fri, Jan 20, 2017 at 03:41:46PM +, Sullivan, Daniel [CRI] wrote:
> Hi,
> 
> I have some more information on this issue.  I’m tracing it down through the 
> slapd logs and  I am continuing to struggle; I was hoping that somebody could 
> possibly help me provided this additional information.
> 
> On the domain logs (on the DC), I see an ldap_search_ext operation 155 with a 
> timeout of 60:
> 
> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
> [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))][cn=Default
>  Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu].
> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 155
> (Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_add] 
> (0x2000): New operation 155 timeout 60
> 
> Then, on the slapd log for the server, I see the incoming request.  Based on 
> the result, it looks like the request completes successfully within 1 second:
> 
> [20/Jan/2017:08:42:35.179890746 -0600] conn=1518 op=31 SRCH base="cn=Default 
> Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu" scope=2 
> filter="(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))" 
> attrs=ALL
> [20/Jan/2017:08:42:35.683485674 -0600] conn=1518 op=31 RESULT err=0 tag=101 
> nentries=0 etime=1 notes=U
> 
> Then, subsequently, the domain log (on the DC), I see the same operation 155 
> timeout (expectedly almost a minute later).

So it looks like ns-ldap send the response but it never reached SSSD in
time. Can you send what it happening in the SSSD logs between 08:42:34
and 08:43:34 (if you prefer you can send it to me directly). Maybe there
is an operation which blocks SSSD for too long so that it returns too
late to the main loop to process the response?

bye,
Sumit

> 
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_timeout] 
> (0x1000): Issuing timeout for 155
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [sdap_op_destructor] (0x1000): Abandoning operation 155
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [generic_ext_search_handler] (0x0040): sdap_get_generic_ext_recv failed 
> [110]: Connection timed out
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [ipa_get_ad_override_done] (0x0040): ipa_get_ad_override request failed.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [sdap_id_op_destroy] (0x4000): releasing operation connection
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [ipa_initgr_get_overrides_override_done] (0x0040): IPA override lookup 
> failed: 110
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [ipa_id_get_groups_overrides_done] (0x0040): IPA resolve user groups 
> overrides failed [110].
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [be_mark_dom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu offline
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [be_mark_subdom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu as 
> inactive
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [ipa_srv_ad_acct_lookup_done] (0x0040): ipa_get_*_acct request failed: [110]: 
> Connection timed out.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [110]: 
> Connection timed out.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [sdap_id_op_destroy] (0x4000): releasing operation connection
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_reply_std_set] (0x0080): DP Error is OK on failed request?
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_done] 
> (0x0400): DP Request [Account #4292]: Request handler finished [0]: Success
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [_dp_req_recv] 
> (0x0400): DP Request [Account #4292]: Receiving request data.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_req_reply_list_success] (0x0400): DP Request [Account #4292]: Finished. 
> Success.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_req_reply_std] (0x1000): DP Request [Account #4292]: Returning [Success]: 
> 0,110,Success
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_table_value_destructor] (0x0400): Removing 
> [0:1:0x0001:1:1::bsdad.uchicago.edu:name=user...@domain.uchicago.edu] from 
> reply table
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_req_destructor] (0x0400): DP Request [Account #4292]: Request removed.
> (Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
> [dp_req_destructor] (0x0400): Number of active DP request: 1
> 
> It seems like whatever problem I have is a communication issue between sssd 
> on the domain 

Re: [Freeipa-users] performance scaling of sssd / freeipa

[Sullivan, Daniel [CRI]]

Hi,

I have some more information on this issue.  I’m tracing it down through the 
slapd logs and  I am continuing to struggle; I was hoping that somebody could 
possibly help me provided this additional information.

On the domain logs (on the DC), I see an ldap_search_ext operation 155 with a 
timeout of 60:

(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))][cn=Default
 Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu].
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 155
(Fri Jan 20 08:42:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_add] 
(0x2000): New operation 155 timeout 60

Then, on the slapd log for the server, I see the incoming request.  Based on 
the result, it looks like the request completes successfully within 1 second:

[20/Jan/2017:08:42:35.179890746 -0600] conn=1518 op=31 SRCH base="cn=Default 
Trust View,cn=views,cn=accounts,dc=xxx,dc=xxx,dc=uchicago,dc=edu" scope=2 
filter="(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-xxx))" 
attrs=ALL
[20/Jan/2017:08:42:35.683485674 -0600] conn=1518 op=31 RESULT err=0 tag=101 
nentries=0 etime=1 notes=U

Then, subsequently, the domain log (on the DC), I see the same operation 155 
timeout (expectedly almost a minute later).

(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [sdap_op_timeout] 
(0x1000): Issuing timeout for 155
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_op_destructor] (0x1000): Abandoning operation 155
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[generic_ext_search_handler] (0x0040): sdap_get_generic_ext_recv failed [110]: 
Connection timed out
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_get_ad_override_done] (0x0040): ipa_get_ad_override request failed.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_initgr_get_overrides_override_done] (0x0040): IPA override lookup failed: 
110
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_id_get_groups_overrides_done] (0x0040): IPA resolve user groups overrides 
failed [110].
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[be_mark_dom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu offline
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[be_mark_subdom_offline] (0x1000): Marking subdomain bsdad.uchicago.edu as 
inactive
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_srv_ad_acct_lookup_done] (0x0040): ipa_get_*_acct request failed: [110]: 
Connection timed out.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [110]: 
Connection timed out.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_reply_std_set] 
(0x0080): DP Error is OK on failed request?
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_done] 
(0x0400): DP Request [Account #4292]: Request handler finished [0]: Success
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [_dp_req_recv] 
(0x0400): DP Request [Account #4292]: Receiving request data.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[dp_req_reply_list_success] (0x0400): DP Request [Account #4292]: Finished. 
Success.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_reply_std] 
(0x1000): DP Request [Account #4292]: Returning [Success]: 0,110,Success
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] 
[dp_table_value_destructor] (0x0400): Removing 
[0:1:0x0001:1:1::bsdad.uchicago.edu:name=user...@domain.uchicago.edu] from 
reply table
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_destructor] 
(0x0400): DP Request [Account #4292]: Request removed.
(Fri Jan 20 08:43:34 2017) [sssd[be[xxx.xxx.uchicago.edu]]] [dp_req_destructor] 
(0x0400): Number of active DP request: 1

It seems like whatever problem I have is a communication issue between sssd on 
the domain controller, and ns-slapd.  I’m starting to venture down the road of 
doing trace/packet level debug logging on the LDAP server; this could be very 
time consuming and frustrating (I already have it enabled, I am starting to 
manipulate the log settings to yield potentially valuable data), I’m hoping 
that somebody might be able to provide some insight based on the information 
above; I can definitely lookup the user on both domain controllers & both IPA 
servers only use themselves for IPA servers.  Thank you so much for reading and 
for your help.

Dan


> On Jan 19, 2017, at 4:15 PM, 

[Freeipa-users] Best way to upgrade IPA servers from Fedora

[Bret Wortman]

Our IPA infrastructure is based entirely on servers running Fedora 21. 
We need (desperately) to upgrade these to C7 or RHEL. All are currently VMs.


Does it make sense to:

1. Add a new host already running C7 to increase our total servers from
   3 to 4 (call it IPA4)
2. Remove IPA1 and upgrade it to C7, install the IPA server packages
   and join it back into the collective
3. Remove IPA2 and upgrade it like IPA1. Add it back.
4. Somehow migrate the CA function to one of the C7 nodes from IPA3.
   Trash or repurpose this VM.

What's the right way to do this? If I've got it right here, what's the 
best way to move the CA function from the node it's on now to one of the 
freshly-upgraded hosts?


Thanks!


--
*Bret Wortman*
Damascus Products
ph/fax: 1-855-644-2783
Wrap Buddies InDemand  at http://bwortman.us/2ieQN4t
-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] be_pam_handler_callback Backend returned: (3, 4, ) [Internal Error (System error)]

[thierry bordaz]

On 01/20/2017 12:23 PM, Harald Dunkel wrote:

On 01/18/17 16:22, Ludwig Krispenz wrote:

I think the procedure in the link about renaming is only needed if you want to keep both 
entries with a "normal" dn. But you want to get rid of the conflict entries.  
Since you have to cleanup each of them individually I would suggest to start with one of 
them.

First get both the conflict entry and the normal entry and compare them:
ldapsearch   -D "cn=directory manager" . -b "cn=System: Manage Host 
Principals,cn=permissions,cn=pbac,dc=example,dc=de" -s base
ldapsearch  -D "cn=directory manager"  . -b "cn=System: Manage Host 
Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de"
 -s base

They should be identical.
Next check if the conflict entry has child entries:
ldapsearch  -D "cn=directory manager"  . -b "cn=System: Manage Host 
Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de"
 dn

If there are no entries below the conflict entry you can remove it:
ldapmodify - D "cn=directory manager" ..
dn: cn=System: Manage Host 
Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de
changetype: delete


Of course they are not identical :-(. Worst case seems to be this
one:

% ldapsearch -o ldif-wrap=no -D "cn=directory manager" -w secret -b "cn=DNS 
Servers+nsuniqueid=109be317-ccd911e6-a5b3d0c8-d8da17db,cn=privileges,cn=pbac,dc=example,dc=de" 
-s base
# extended LDIF
#
# LDAPv3
# base 

Re: [Freeipa-users] be_pam_handler_callback Backend returned: (3, 4, ) [Internal Error (System error)]

[Harald Dunkel]

On 01/18/17 16:22, Ludwig Krispenz wrote:
> I think the procedure in the link about renaming is only needed if you want 
> to keep both entries with a "normal" dn. But you want to get rid of the 
> conflict entries.  Since you have to cleanup each of them individually I 
> would suggest to start with one of them.
> 
> First get both the conflict entry and the normal entry and compare them:
> ldapsearch   -D "cn=directory manager" . -b "cn=System: Manage Host 
> Principals,cn=permissions,cn=pbac,dc=example,dc=de" -s base
> ldapsearch  -D "cn=directory manager"  . -b "cn=System: Manage Host 
> Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de"
>  -s base
> 
> They should be identical.
> Next check if the conflict entry has child entries:
> ldapsearch  -D "cn=directory manager"  . -b "cn=System: Manage Host 
> Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de"
>  dn
> 
> If there are no entries below the conflict entry you can remove it:
> ldapmodify - D "cn=directory manager" ..
> dn: cn=System: Manage Host 
> Principals+nsuniqueid=109be36e-ccd911e6-a5b3d0c8-d8da17db,cn=permissions,cn=pbac,dc=example,dc=de
> changetype: delete
> 

Of course they are not identical :-(. Worst case seems to be this
one:

% ldapsearch -o ldif-wrap=no -D "cn=directory manager" -w secret -b "cn=DNS 
Servers+nsuniqueid=109be317-ccd911e6-a5b3d0c8-d8da17db,cn=privileges,cn=pbac,dc=example,dc=de"
 -s base
# extended LDIF
#
# LDAPv3
# base 

Re: [Freeipa-users] be_pam_handler_callback Backend returned: (3, 4, ) [Internal Error (System error)]

[Ludwig Krispenz]

thanks for the info

Ludwig

On 01/20/2017 11:43 AM, Harald Dunkel wrote:

On 01/19/17 16:23, Harald Dunkel wrote:

Now I get this:

[root@ipa1 ~]# kinit admin
kinit: Generic error (see e-text) while getting initial credentials


Fortunately this went away after a reboot of the servers.

Phew
Harri



--
Red Hat GmbH, http://www.de.redhat.com/, Registered seat: Grasbrunn,
Commercial register: Amtsgericht Muenchen, HRB 153243,
Managing Directors: Charles Cachera, Michael Cunningham, Michael O'Neill, Eric 
Shander

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] be_pam_handler_callback Backend returned: (3, 4, ) [Internal Error (System error)]

[Harald Dunkel]

On 01/19/17 16:23, Harald Dunkel wrote:
> Now I get this:
> 
> [root@ipa1 ~]# kinit admin
> kinit: Generic error (see e-text) while getting initial credentials
> 
Fortunately this went away after a reboot of the servers.

Phew
Harri

-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] manually apply patches from upstream

[Alexander Bokovoy]

On pe, 20 tammi 2017, Jeff Clay wrote:

I found this information here http://www.freeipa.org/page/Build
 on building, which makes sense
enough… I setup that environment on my Centos box, tracked down all the
dependancies to satisfy yum-builddep freeipa-builddep.spec. However,
when I checkout the 4.4.3 branch, there isn’t a makerpms.sh file so
that really through me off. When trying to run the makerpms.sh on the
master branch, it kept erroring at:

checking for POPT... no
configure: error: Package requirements (popt) were not met:

No package 'popt' found

Consider adjusting the PKG_CONFIG_PATH environment variable if you
installed software in a non-standard prefix.

Alternatively, you may set the environment variables POPT_CFLAGS
and POPT_LIBS to avoid the need to call pkg-config.
See the pkg-config man page for more details.

I have the following installed:

Installed Packages
popt.x86_64 
  1.13-16.el7   
 @anaconda
popt-devel.x86_64   
  1.13-16.el7   
 @base
popt-static.x86_64  
  1.13-16.el7

and verified its location

/usr/include/popt.h
/usr/lib/rpm/rpmpopt-4.11.3
/usr/lib64/libpopt.so
/usr/lib64/libpopt.so.0
/usr/lib64/libpopt.so.0.0.0

All of the above was done prior to seeing the last reply giving the
location of the Centos IPA repo. I’m not the most familiar with git
stuff, but all i could find in that repo were .patch files. I couldn’t
locate any actual files other than a readme.

Read https://wiki.centos.org/Sources which describes how to work with
CentOS git repositories. There is an example workflow how to download
patches, spec, and sources, and then rebuild the packages.

--
/ Alexander Bokovoy

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Re: [Freeipa-users] manually apply patches from upstream

[Jeff Clay]

I found this information here http://www.freeipa.org/page/Build 
 on building, which makes sense enough… I 
setup that environment on my Centos box, tracked down all the dependancies to 
satisfy yum-builddep freeipa-builddep.spec. However, when I checkout the 4.4.3 
branch, there isn’t a makerpms.sh file so that really through me off. When 
trying to run the makerpms.sh on the master branch, it kept erroring at:

checking for POPT... no
configure: error: Package requirements (popt) were not met:

No package 'popt' found

Consider adjusting the PKG_CONFIG_PATH environment variable if you
installed software in a non-standard prefix.

Alternatively, you may set the environment variables POPT_CFLAGS
and POPT_LIBS to avoid the need to call pkg-config.
See the pkg-config man page for more details.

I have the following installed:

Installed Packages
popt.x86_64 
  1.13-16.el7   
 @anaconda
popt-devel.x86_64   
  1.13-16.el7   
 @base
popt-static.x86_64  
  1.13-16.el7 

and verified its location

/usr/include/popt.h
/usr/lib/rpm/rpmpopt-4.11.3
/usr/lib64/libpopt.so
/usr/lib64/libpopt.so.0
/usr/lib64/libpopt.so.0.0.0

All of the above was done prior to seeing the last reply giving the location of 
the Centos IPA repo. I’m not the most familiar with git stuff, but all i could 
find in that repo were .patch files. I couldn’t locate any actual files other 
than a readme.

Thanks for the help.


> On Jan 20, 2017, at 1:06 AM, David Kupka  wrote:
> 
> On 20/01/17 06:23, Jeff Clay wrote:
>> I’m using Centos 7 and have installed 4.4.0-14, however I’m using Google 
>> Cloud and needing some updates that have already been made upstream at 
>> https://fedorahosted.org/freeipa/ticket/5814 
>> 
>> 
>> I have downloaded the diffs from the 3 commits to the 4.4 branch. Searching 
>> my system for the proper directories, I found that many of the files (like 
>> replicainstall.py) can be found in a sub dir of of 
>> /usr/lib/python2.7/site-packages/ while other parts can be found in 
>> /usr/sbin/
>> 
>> I’m just wondering what is the best and proper way for me to apply those 
>> code changes?
>> 
>> Thanks.
>> 
>> 
>> 
> Hello Jeff,
> modifying package-installed "binaries" or "libraries" on production system is 
> really bad idea. You may easily end up with system broken in numerous ways.
> Proper way is to get CentOS downstream git clone [1] add the desired patches 
> and build your own package.
> 
> [1] https://git.centos.org/commit/rpms!ipa.git
> 
> -- 
> David Kupka

-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project