AD Provider: dereference processing failed : Invalid argument

[sssd-bot]

Cloned from Pagure issue: https://pagure.io/SSSD/sssd/issue/3771

• Created at 2018-07-11 03:03:25 by irekp
• Closed at 2018-07-11 04:48:15 as Fixed
• Assigned to nobody

---

I have installed the latest version of Centos 7.5.1804 ( sssd-1.16.0-19.el7_5.5.x86_64 ) and I have noticed that when SSSD query some groups the response it empty. The same query on Centos 7.4.1708 ( sssd-1.15.2-50.el7_4.11.x86_64 ) works ok.

I am joining to AD by command : realm join -U
I am doing query by "getent group <group_name>"

I have enabled full debug and find that SSSD is having issue to pull the list of users from the group.
Just don't understand why?

This is what I have found in the logs:

Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sysdb_cache_search_groups] (0x2000): No such entry
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_group_split_members] (0x4000): [CN=XXXX,OU=XXX,OU=XXX,DC=xx,DC=xx,DC=xx] is unknown object
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_group_process_send] (0x0400): More members were missing than the deref threshold
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_group_process_send] (0x2000): Looking up 11/27 members of group [CN=xxx,OU=xxxx,DC=xx,DC=xx,DC=xx]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_group_process_send] (0x2000): Dereferencing members of group [CN=xxx,DC=xx,DC=xx,DC=xxx]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_deref_search_send] (0x2000): Server supports ASQ
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_asq_search_send] (0x0400): Dereferencing entry [CN=xxx,DC=xx,DC=xxx,DC=xx] using ASQ
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_print_server] (0x2000): Searching 1xx.2xx.9x.1xx:3268
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_send] (0x0400): WARNING: Disabling paging becxxse scope is set to base.
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=xxx,OU=xxx,DC=xx,DC=xx,DC=xx].
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [member]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [groupType]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_op_add] (0x2000): New operation 5 timeout 6
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_result] (0x2000): Trace: sh[0x55a02ba21170], connected[1], ops[(nil)], ldap[0x55a02ba1f4c0]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_result] (0x2000): Trace: sh[0x55a02ba4ead0], connected[1], ops[0x55a02ba4f1b0], ldap[0x55a02ba35470]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_asq_search_parse_entry] (0x2000): Matched objectclass [user] on DN [CN=XXX,OU=xx,DC=xx,DC=xx,DC=xx], will use associated map
......

(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_get_generic_op_finished] (0x0020): reply parsing callback failed.
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_op_destructor] (0x1000): Abandoning operation 5
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [generic_ext_search_handler] (0x0040): sdap_get_generic_ext_recv failed [22]: Invalid argument
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_deref_search_done] (0x0040): dereference processing failed [22]: Invalid argument
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_group_deref_direct_done] (0x0020): Error processing direct membership [22]: Invalid argument
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_nested_done] (0x0020): Nested group processing failed: [22][Invalid argument]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_req_done] (0x0400): DP Request [Account #1]: Request handler finished [0]: Success
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [_dp_req_recv] (0x0400): DP Request [Account #1]: Receiving request data.
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1]: Finished. Success.
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_req_reply_std] (0x1000): DP Request [Account #1]: Returning [Internal Error]: 3,22,Group lookup failed
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2::xx.xxx.xx:name=xxxxx@xx.xxx.xx] from reply table
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_req_destructor] (0x0400): DP Request [Account #1]: Request removed.
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_result] (0x2000): Trace: sh[0x55a02ba4ead0], connected[1], ops[(nil)], ldap[0x55a02ba35470]
(Wed Jul 11 08:33:41 2018) [sssd[be[xx.xxx.xx]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list
(Wed Jul 11 08:33:46 2018) [sssd[be[xx.xxx.xx]]] [sbus_dispatch] (0x4000): dbus conn: 0x55a02ba30d10
(Wed Jul 11 08:33:46 2018) [sssd[be[xx.xxx.xx]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jul 11 08:33:46 2018) [sssd[be[xx.xxx.xx]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider
(Wed Jul 11 08:33:46 2018) [sssd[be[xx.xxx.xx]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit

Thanks,
Irek

Comments

---

Comment from irekp at 2018-07-11 04:47:46

I have found the problem.
The new server had restriction in AD and it wasn't able to see full list of the users in the group.

weird problem, we can close the issue

-Irek

---

Comment from irekp at 2018-07-11 04:48:16

Metadata Update from @irekp:

• Issue close_status updated to: Fixed
• Issue status updated to: Closed (was: Open)

---

Comment from jamalm at 2019-08-22 12:39:24

Hi Irek,

We are encountering the same type of issue and it causes us to lose a group quite often, could you maybe provide some info on the "restriction" you had in AD?

Thanks,
Jamal

---

Comment from irekp at 2019-08-23 00:09:59

Hi Jamal,

I am not AD expert but the account which I am using has restriction what ca=
n see in AD. The AD administrators can restrict which tree you can see an w=
hat field of the account as well.
My upgrade synchronise with the changes in our AD which I didn't know I was=
blaming SSS for the issue.

Good luck.

Irek

---

From: Jamal Mahmoud pagure@pagure.io
Sent: Thursday, 22 August 2019 8:39 PM
To: Irek Porebski i.porebski@uq.edu.au
Subject: [SSSD/sssd] Issue #3771: AD Provider: dereference processing faile=
d : Invalid argument

jamalm added a new comment to an issue you are following:
``
Hi Irek,

We are encountering the same type of issue and it causes us to lose a group=
quite often, could you maybe provide some info on the "restriction" you ha=
d in AD?

Thanks,
Jamal
``

To reply, visit the link below or just reply to this email
https://pagure.io/SSSD/sssd/issue/3771