Hi,
we have a setup with a Forest Trust to an AD Domain.
Everything looks good on the FreeIPA Servers itself. We can see User information if we do "getent passwd user@ad.domain" or "id user@ad.domain" or "sssctl user-checks user@ad.domain".
But on a connected client, we get only the user of the ipa domain and no user information on ad user.
In the logs, we found no obvious error. The only thing we see in sssd.log is: (Tue Jul 10 16:19:27 2018) [sssd[be[ipa.domain]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user@ad.domain] (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: No such object(32), (null). (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed.
Best Regards, Axel
On Tue, Jul 10, 2018 at 02:25:53PM -0000, tolotos--- via FreeIPA-users wrote:
Hi,
we have a setup with a Forest Trust to an AD Domain.
Everything looks good on the FreeIPA Servers itself. We can see User information if we do "getent passwd user@ad.domain" or "id user@ad.domain" or "sssctl user-checks user@ad.domain".
But on a connected client, we get only the user of the ipa domain and no user information on ad user.
In the logs, we found no obvious error. The only thing we see in sssd.log is: (Tue Jul 10 16:19:27 2018) [sssd[be[ipa.domain]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user@ad.domain] (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: No such object(32), (null). (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed.
Are all the groups the user is a member of resolvable by ID? (getent group $GID) ?
A good way to debug this kind of issues is to enable debugging in the [nss] section in sssd.conf on the IPA server and check if any of the requests goes unanswered.
On ti, 10 heinä 2018, tolotos--- via FreeIPA-users wrote:
Hi,
we have a setup with a Forest Trust to an AD Domain.
Everything looks good on the FreeIPA Servers itself. We can see User information if we do "getent passwd user@ad.domain" or "id user@ad.domain" or "sssctl user-checks user@ad.domain".
But on a connected client, we get only the user of the ipa domain and no user information on ad user.
In the logs, we found no obvious error. The only thing we see in sssd.log is: (Tue Jul 10 16:19:27 2018) [sssd[be[ipa.domain]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=user@ad.domain] (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: No such object(32), (null). (Tue Jul 10 16:19:28 2018) [sssd[be[ipa.domain]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed.
Enable sssd logs on IPA server (debug_level=9 in the domain section), restart sssd, retry access for the client so that you get the same s2n exop request failed response. Collect logs from sssd domain log for the time period, show them.
Also show versions of freeipa-server and sssd.
Hi,
thanks for the response.
Server: - FreeIPA 4.5.4 - SSSD 1.16.0
ClientA: - SSSD 1.16.0
ClientB: - SSSD 1.16.1
Log on server side is: ---<start>--- (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_dispatch] (0x4000): dbus conn: 0x5642c3a76bb0 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountDomain on path /org/freedesktop/sssd/dataprovider (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_attach_req] (0x0400): DP Request [AccountDomain #1]: New request. Flags [0000]. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_done] (0x0400): DP Request [AccountDomain #1]: Request handler finished [0]: Success (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [_dp_req_recv] (0x0400): DP Request [AccountDomain #1]: Receiving request data. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_reply_list_success] (0x0400): DP Request [AccountDomain #1]: Finished. Success. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_reply_std] (0x1000): DP Request [AccountDomain #1]: Returning [Internal Error]: 3,1432158298,GetAccountDomain() not supported (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_table_value_destructor] (0x0400): Removing [0:10:0000:0x5642c3a8ef50] from reply table (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_destructor] (0x0400): DP Request [AccountDomain #1]: Request removed. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_dispatch] (0x4000): dbus conn: 0x5642c3a76bb0 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_get_account_info_handler] (0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=12345] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_attach_req] (0x0400): DP Request [Account #2]: New request. Flags [0x0001]. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sss_domain_get_state] (0x1000): Domain ipa.domain is Active (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sss_domain_get_state] (0x1000): Domain ipa.domain is Active (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [cn=accounts,dc=ipa,dc=domain] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_print_server] (0x2000): Searching 10.139.16.73:389 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=12345)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=ipa,dc=domain]. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [posixGroup] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaUniqueID] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaNTSecurityIdentifier] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaExternalMember] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 13 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_op_add] (0x2000): New operation 13 timeout 6 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_process_result] (0x2000): Trace: sh[0x5642c3a90e30], connected[1], ops[0x5642c3a85ba0], ldap[0x5642c3a91b50] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_op_destructor] (0x2000): Operation 13 finished (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 0 results. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_id_op_done] (0x4000): releasing operation connection (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x5642c3b2c460 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x5642c3b2c520 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Running timer event 0x5642c3b2c460 "ltdb_callback" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Destroying timer event 0x5642c3b2c520 "ltdb_timeout" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Ending timer event 0x5642c3b2c460 "ltdb_callback" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sysdb_search_group_by_gid] (0x0400): No such entry (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sysdb_delete_group] (0x0400): Error: 2 (No such file or directory) (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x5642c3ac0470 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x5642c3ac0530 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Running timer event 0x5642c3ac0470 "ltdb_callback" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Destroying timer event 0x5642c3ac0530 "ltdb_timeout" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ldb] (0x4000): Ending timer event 0x5642c3ac0470 "ltdb_callback" (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sysdb_search_group_by_gid] (0x0400): No such entry (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [ipa_id_get_account_info_orig_done] (0x0080): Object not found, ending request (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_done] (0x0400): DP Request [Account #2]: Request handler finished [0]: Success (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [_dp_req_recv] (0x0400): DP Request [Account #2]: Receiving request data. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #2]: Finished. Success. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_reply_std] (0x1000): DP Request [Account #2]: Returning [Success]: 0,0,Success (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2::ipa.domain:idnumber=12345] from reply table (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_destructor] (0x0400): DP Request [Account #2]: Request removed. (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_process_result] (0x2000): Trace: sh[0x5642c3a90e30], connected[1], ops[(nil)], ldap[0x5642c3a91b50] (Tue Jul 10 17:35:39 2018) [sssd[be[ipa.domain]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ---<end>---
The log on client side is huge. I don't know a proper way to attach this.
Additionally, we looked for the object nor found in logs of the directory server and found:
---<start>--- [10/Jul/2018:17:35:38.347674161 +0200] conn=127 fd=111 slot=111 connection from 1.1.1.1 to 2.2.2.2 [10/Jul/2018:17:35:38.347983729 +0200] conn=127 op=0 SRCH base="" scope=0 filter="(objectClass=*)" attrs="* altServer namingContexts supportedControl supportedExtension supportedFeatures supportedLDAPVersion supportedSASLMechanisms domaincontrollerfunctionality defaultnamingcontext lastusn highestcommittedusn aci" [10/Jul/2018:17:35:38.349188753 +0200] conn=127 op=0 RESULT err=0 tag=101 nentries=1 etime=0.0001471044 [10/Jul/2018:17:35:38.384186460 +0200] conn=127 op=1 BIND dn="" method=sasl version=3 mech=GSSAPI [10/Jul/2018:17:35:38.388485306 +0200] conn=127 op=1 RESULT err=14 tag=97 nentries=0 etime=0.0004336798, SASL bind in progress [10/Jul/2018:17:35:38.388828913 +0200] conn=127 op=2 BIND dn="" method=sasl version=3 mech=GSSAPI [10/Jul/2018:17:35:38.389950826 +0200] conn=127 op=2 RESULT err=14 tag=97 nentries=0 etime=0.0001177539, SASL bind in progress [10/Jul/2018:17:35:38.390078262 +0200] conn=127 op=3 BIND dn="" method=sasl version=3 mech=GSSAPI [10/Jul/2018:17:35:38.390581136 +0200] conn=127 op=3 RESULT err=0 tag=97 nentries=0 etime=0.0000540148 dn="fqdn=clientA.ipa.domain,cn=computers,cn=accounts,dc=ipa,dc=domain" [10/Jul/2018:17:35:38.390984153 +0200] conn=127 op=4 SRCH base="cn=accounts,dc=ipa,dc=domain" scope=2 filter="(&(objectClass=ipaHost)(fqdn=clientA.ipa.domain))" attrs="objectClass cn fqdn serverHostName memberOf ipaSshPubKey ipaUniqueID" [10/Jul/2018:17:35:38.391088333 +0200] conn=127 op=5 SRCH base="cn=ranges,cn=etc,dc=ipa,dc=domain" scope=2 filter="(objectClass=ipaIDRange)" attrs="objectClass cn ipaBaseID ipaBaseRID ipaSecondaryBaseRID ipaIDRangeSize ipaNTTrustedDomainSID ipaRangeType" [10/Jul/2018:17:35:38.391896981 +0200] conn=127 op=4 RESULT err=0 tag=101 nentries=1 etime=0.0001010012 notes=P pr_idx=0 pr_cookie=-1 [10/Jul/2018:17:35:38.393305332 +0200] conn=127 op=6 SRCH base="fqdn=clientA.ipa.domain,cn=computers,cn=accounts,dc=ipa,dc=domain" scope=0 filter="(objectClass=*)" attrs="objectClass cn memberOf ipaUniqueID" [10/Jul/2018:17:35:38.393634331 +0200] conn=127 op=6 RESULT err=0 tag=101 nentries=1 etime=0.0001197516 notes=P pr_idx=0 pr_cookie=-1 [10/Jul/2018:17:35:38.394343633 +0200] conn=127 op=7 SRCH base="cn=sudo,dc=ipa,dc=domain" scope=2 filter="(&(objectClass=ipasudorule)(ipaEnabledFlag=TRUE)(|(!(memberHost=*))(hostCategory=ALL)(memberHost=fqdn=clientA.ipa.domain,cn=computers,cn=accounts,dc=ipa,dc=domain)))" attrs="objectClass cn ipaUniqueID ipaEnabledFlag ipaSudoOpt ipaSudoRunAs ipaSudoRunAsGroup memberAllowCmd memberDenyCmd memberHost memberUser sudoNotAfter sudoNotBefore sudoOrder cmdCategory hostCategory userCategory ipaSudoRunAsUserCategory ipaSudoRunAsGroupCategory ipaSudoRunAsExtUser ipaSudoRunAsExtGroup ipaSudoRunAsExtUserGroup externalUser entryusn" [10/Jul/2018:17:35:38.394441980 +0200] conn=127 op=7 RESULT err=0 tag=101 nentries=0 etime=0.0000224206 notes=P pr_idx=0 pr_cookie=-1 [10/Jul/2018:17:35:38.394626354 +0200] conn=127 op=5 RESULT err=0 tag=101 nentries=13 etime=0.0003631823 [10/Jul/2018:17:35:38.457670149 +0200] conn=127 op=8 SRCH base="cn=certmap,dc=ipa,dc=domain" scope=2 filter="(|(&(objectClass=ipaCertMapRule)(ipaEnabledFlag=TRUE))(objectClass=ipaCertMapConfigObject))" attrs="objectClass cn ipaCertMapMapRule ipaCertMapMatchRule ipaCertMapPriority associatedDomain ipaCertMapPromptUsername" [10/Jul/2018:17:35:38.458069059 +0200] conn=127 op=8 RESULT err=0 tag=101 nentries=1 etime=0.0000538763 [10/Jul/2018:17:35:38.467002124 +0200] conn=127 op=9 SRCH base="cn=ad,cn=etc,dc=ipa,dc=domain" scope=2 filter="(objectClass=ipaNTDomainAttrs)" attrs="cn ipaNTFlatName ipaNTSecurityIdentifier ipaNTAdditionalSuffixes" [10/Jul/2018:17:35:38.467320155 +0200] conn=127 op=9 RESULT err=0 tag=101 nentries=1 etime=0.0000397006 [10/Jul/2018:17:35:38.476169636 +0200] conn=127 op=10 SRCH base="cn=trusts,dc=ipa,dc=domain" scope=2 filter="(objectClass=ipaNTTrustedDomain)" attrs="cn ipaNTFlatName ipaNTTrustedDomainSID ipaNTTrustDirection ipaNTAdditionalSuffixes" [10/Jul/2018:17:35:38.477602102 +0200] conn=127 op=10 RESULT err=0 tag=101 nentries=12 etime=0.0001497976 [10/Jul/2018:17:35:39.033346247 +0200] conn=127 op=11 SRCH base="cn=accounts,dc=ipa,dc=domain" scope=2 filter="(&(objectClass=ipaHost)(fqdn=clientA.ipa.domain))" attrs="cn objectClass" [10/Jul/2018:17:35:39.034190881 +0200] conn=127 op=11 RESULT err=0 tag=101 nentries=1 etime=0.0001004739 notes=P pr_idx=0 pr_cookie=-1 [10/Jul/2018:17:35:39.049737515 +0200] conn=127 op=12 SRCH base="cn=default,cn=views,cn=accounts,dc=ipa,dc=domain" scope=0 filter="(objectClass=*)" attrs="ipaDomainResolutionOrder" [10/Jul/2018:17:35:39.050025836 +0200] conn=127 op=12 RESULT err=0 tag=101 nentries=0 etime=0.0000410445 [10/Jul/2018:17:35:39.062405579 +0200] conn=127 op=13 SRCH base="cn=etc,dc=ipa,dc=domain" scope=2 filter="(&(cn=ipaConfig)(objectClass=ipaGuiConfig))" attrs="ipaDomainResolutionOrder" [10/Jul/2018:17:35:39.062766272 +0200] conn=127 op=13 RESULT err=0 tag=101 nentries=1 etime=0.0000465826 [10/Jul/2018:17:35:39.191274237 +0200] conn=127 op=14 SRCH base="cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=domain" scope=2 filter="(&(objectClass=ipaUserOverride)(uid=user))" attrs=ALL [10/Jul/2018:17:35:39.191679382 +0200] conn=127 op=14 RESULT err=0 tag=101 nentries=0 etime=0.0000558335 [10/Jul/2018:17:35:39.192053326 +0200] conn=127 op=15 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.225780038 +0200] conn=127 op=15 RESULT err=32 tag=120 nentries=0 etime=0.0033806710 [10/Jul/2018:17:35:39.226948196 +0200] conn=127 op=16 SRCH base="cn=accounts,dc=ipa,dc=domain" scope=2 filter="(&(|(krbPrincipalName=user@ad.domain)(mail=user@ad.domain)(krbPrincipalName=user\5C@ad.domain@ipa.domain))(objectClass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))" attrs="objectClass uid userPassword uidNumber gidNumber gecos homeDirectory loginShell krbPrincipalName cn memberOf ipaUniqueID ipaNTSecurityIdentifier modifyTimestamp entryusn shadowLastChange shadowMin shadowMax shadowWarning shadowInactive shadowExpire shadowFlag krbLastPwdChange krbPasswordExpiration pwdattribute authorizedService accountexpires useraccountcontrol nsAccountLock host logindisabled loginexpirationtime loginallowedtimemap ipaSshPubKey ipaUserAuthType usercertificate;binary mail" [10/Jul/2018:17:35:39.227109793 +0200] conn=127 op=16 RESULT err=0 tag=101 nentries=0 etime=0.0000293114 [10/Jul/2018:17:35:39.228116765 +0200] conn=127 op=17 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.228913482 +0200] conn=127 op=17 RESULT err=32 tag=120 nentries=0 etime=0.0000839763 [10/Jul/2018:17:35:39.229475359 +0200] conn=127 op=18 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.229760276 +0200] conn=127 op=18 RESULT err=32 tag=120 nentries=0 etime=0.0000333380 [10/Jul/2018:17:35:39.230323835 +0200] conn=127 op=19 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.230541786 +0200] conn=127 op=19 RESULT err=32 tag=120 nentries=0 etime=0.0000258722 [10/Jul/2018:17:35:39.231116494 +0200] conn=127 op=20 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.231336902 +0200] conn=127 op=20 RESULT err=32 tag=120 nentries=0 etime=0.0000261215 [10/Jul/2018:17:35:39.231925682 +0200] conn=127 op=21 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.232155918 +0200] conn=127 op=21 RESULT err=32 tag=120 nentries=0 etime=0.0000269858 [10/Jul/2018:17:35:39.232756122 +0200] conn=127 op=22 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.232942082 +0200] conn=127 op=22 RESULT err=32 tag=120 nentries=0 etime=0.0000214566 [10/Jul/2018:17:35:39.233600237 +0200] conn=127 op=23 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.233808007 +0200] conn=127 op=23 RESULT err=32 tag=120 nentries=0 etime=0.0000257569 [10/Jul/2018:17:35:39.234482488 +0200] conn=127 op=24 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.234709809 +0200] conn=127 op=24 RESULT err=32 tag=120 nentries=0 etime=0.0000266410 [10/Jul/2018:17:35:39.235388998 +0200] conn=127 op=25 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.235601720 +0200] conn=127 op=25 RESULT err=32 tag=120 nentries=0 etime=0.0000253084 [10/Jul/2018:17:35:39.236292779 +0200] conn=127 op=26 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.236502684 +0200] conn=127 op=26 RESULT err=32 tag=120 nentries=0 etime=0.0000240154 [10/Jul/2018:17:35:39.237217004 +0200] conn=127 op=27 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.237431843 +0200] conn=127 op=27 RESULT err=32 tag=120 nentries=0 etime=0.0000243316 [10/Jul/2018:17:35:39.238156464 +0200] conn=127 op=28 EXT oid="2.16.840.1.113730.3.8.10.4.1" name="IPA trusted domain ID mapper" [10/Jul/2018:17:35:39.238365882 +0200] conn=127 op=28 RESULT err=32 tag=120 nentries=0 etime=0.0000233365 ---<stop>---
Best Regards, Axel
Hi,
we have done some additional testing and debugging.
It seems there some problems with the extdom-extop plugin in the directory server.
If we set ignore_group_members, the first request get a good response. (tested by: server: sssctl cache-remove -p -s -o ; sleep 1; stop-dirsrv ; sleep 1; start-dirsrv / client: sssctl cache-remove -p -s -o ; sleep 1; sssctl user-checks user@ad.domain)
However, starting with the second requests the extdom-extop returns every request with an err=32 Object Not Found.
We already tried to increase ipaextdommaxnssbufsize and ipaextdommaxnsstimeout. (we increased error log level on dirsrv to be sure that the values are used: Maximal nss buffer size set to [268435456]! / Maximal nss timeout (in ms) set to [100000]!)
Someone some ideas where to look from here?
Best Regards, Axel
On to, 12 heinä 2018, tolotos--- via FreeIPA-users wrote:
Hi,
we have done some additional testing and debugging.
It seems there some problems with the extdom-extop plugin in the directory server.
If we set ignore_group_members, the first request get a good response. (tested by: server: sssctl cache-remove -p -s -o ; sleep 1; stop-dirsrv ; sleep 1; start-dirsrv / client: sssctl cache-remove -p -s -o ; sleep 1; sssctl user-checks user@ad.domain)
However, starting with the second requests the extdom-extop returns every request with an err=32 Object Not Found.
We already tried to increase ipaextdommaxnssbufsize and ipaextdommaxnsstimeout. (we increased error log level on dirsrv to be sure that the values are used: Maximal nss buffer size set to [268435456]! / Maximal nss timeout (in ms) set to [100000]!)
Someone some ideas where to look from here?
Setting ignore_group_members on IPA masters does not really allow extdom plugin to work well.
However, did you try to increase timeouts in sssd on IPA master? Extdom plugin calls out to SSSD on IPA master when any request comes to it via LDAP extended operation. So the plugin itself doesn't really do anything, sssd on IPA master does all the heavy lifting. Extdom plugin only translates an anwer given by SSSD.
On Thu, Jul 12, 2018 at 10:54:55AM +0300, Alexander Bokovoy via FreeIPA-users wrote:
On to, 12 heinä 2018, tolotos--- via FreeIPA-users wrote:
Hi,
we have done some additional testing and debugging.
It seems there some problems with the extdom-extop plugin in the directory server.
If we set ignore_group_members, the first request get a good response. (tested by: server: sssctl cache-remove -p -s -o ; sleep 1; stop-dirsrv ; sleep 1; start-dirsrv / client: sssctl cache-remove -p -s -o ; sleep 1; sssctl user-checks user@ad.domain)
However, starting with the second requests the extdom-extop returns every request with an err=32 Object Not Found.
We already tried to increase ipaextdommaxnssbufsize and ipaextdommaxnsstimeout. (we increased error log level on dirsrv to be sure that the values are used: Maximal nss buffer size set to [268435456]! / Maximal nss timeout (in ms) set to [100000]!)
Someone some ideas where to look from here?
Setting ignore_group_members on IPA masters does not really allow extdom plugin to work well.
Are you sure? I've seen quite a few users enabling this switch..
(Maybe you meant the compat tree which also publishes the group members?)
However, did you try to increase timeouts in sssd on IPA master? Extdom plugin calls out to SSSD on IPA master when any request comes to it via LDAP extended operation. So the plugin itself doesn't really do anything, sssd on IPA master does all the heavy lifting. Extdom plugin only translates an anwer given by SSSD.
On to, 12 heinä 2018, Jakub Hrozek via FreeIPA-users wrote:
On Thu, Jul 12, 2018 at 10:54:55AM +0300, Alexander Bokovoy via FreeIPA-users wrote:
On to, 12 heinä 2018, tolotos--- via FreeIPA-users wrote:
Hi,
we have done some additional testing and debugging.
It seems there some problems with the extdom-extop plugin in the directory server.
If we set ignore_group_members, the first request get a good response. (tested by: server: sssctl cache-remove -p -s -o ; sleep 1; stop-dirsrv ; sleep 1; start-dirsrv / client: sssctl cache-remove -p -s -o ; sleep 1; sssctl user-checks user@ad.domain)
However, starting with the second requests the extdom-extop returns every request with an err=32 Object Not Found.
We already tried to increase ipaextdommaxnssbufsize and ipaextdommaxnsstimeout. (we increased error log level on dirsrv to be sure that the values are used: Maximal nss buffer size set to [268435456]! / Maximal nss timeout (in ms) set to [100000]!)
Someone some ideas where to look from here?
Setting ignore_group_members on IPA masters does not really allow extdom plugin to work well.
Are you sure? I've seen quite a few users enabling this switch..
(Maybe you meant the compat tree which also publishes the group members?)
Compat tree does exactly same calls like extdom plugin. They both retrieve membership information from sssd.
Hi,
hmm, it seems that it has done in a different way. We have compat tree acive and it contains the ad users without a problem.
Best Regards, Axel
Hi,
no we don't have special timeout settings in sssd.conf. Wich parameters you would recommend to set?
Due to the assumption that all seem to work at the moment when all caches/buffers are empty, we experiment with modifying the cache files in /var/lib/sss/db/cache*.ldb with the ldb-tools. And if we remove all entries in this cache file (ldbdel) the next requests work again.
Best Regards, Axel
On Thu, Jul 12, 2018 at 08:49:37AM -0000, tolotos--- via FreeIPA-users wrote:
Hi,
no we don't have special timeout settings in sssd.conf. Wich parameters you would recommend to set?
Due to the assumption that all seem to work at the moment when all caches/buffers are empty, we experiment with modifying the cache files in /var/lib/sss/db/cache*.ldb with the ldb-tools. And if we remove all entries in this cache file (ldbdel) the next requests work again.
This is really strange, are you nuking the cache on the client or the server?
Can you paste some logs?
Hi,
the *.ldb files are manipulated on the server. On the client, we have removed the cache via sssctl.
What logs exactly, besides the logs i already posted?
Best Regards, Axel
On Thu, Jul 12, 2018 at 09:50:14AM -0000, tolotos--- via FreeIPA-users wrote:
Hi,
the *.ldb files are manipulated on the server. On the client, we have removed the cache via sssctl.
What logs exactly, besides the logs i already posted?
SSSD NSS and domain logs of the failing lookup while the cache is in the 'bad' state.
Hi,
thanks so far to all help up to this point.
We have done some more testing without a correct solution.
At the moment we are reproducing this on a separate environment and we will also open a case at RH via RHEL subscription.
Best Regards, Axel
freeipa-users@lists.fedorahosted.org