Bug 819063 - sssd fails to provide partial data till paged search returns "Size Limit Exceeded"
sssd fails to provide partial data till paged search returns "Size Limit Exce...
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: sssd (Show other bugs)
6.3
Unspecified Unspecified
high Severity unspecified
: rc
: ---
Assigned To: Stephen Gallagher
IDM QE LIST
: Regression
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-05-04 13:43 EDT by Kaushik Banerjee
Modified: 2012-06-20 07:56 EDT (History)
4 users (show)

See Also:
Fixed In Version: sssd-1.8.0-26.el6
Doc Type: Bug Fix
Doc Text:
No documentation required
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-06-20 07:56:55 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Kaushik Banerjee 2012-05-04 13:43:50 EDT
Description of problem:
sssd fails to provide partial data till paged search returns "Size Limit Exceeded"

Version-Release number of selected component (if applicable):
1.8.0-25

How reproducible:
Always

Steps to Reproduce:
1. On openldap server, set maxpagesize=10,totalpageentries=5 as:
 
olcLimits: * size.pr=10 size.prtotal=5

2. Add a user puser21, belonging to 20 groups

3. Use ldapsearch to verify if 5 paged entries are returned:
# ldapsearch -xv -h openldap.example.com -E pr=05 -b "ou=Pagingtest,dc=example,dc=com" "(memberuid=puser21)"
ldap_initialize( ldap://openldap.example.com )
filter: (memberuid=puser21)
requesting: All userApplication attributes
# extended LDIF
#
# LDAPv3
# base <ou=Pagingtest,dc=example,dc=com> with scope subtree
# filter: (memberuid=puser21)
# requesting: ALL
# with pagedResults control: size=5
#
 
# puser21_grp1, Pagingtest, example.com
dn: cn=puser21_grp1,ou=Pagingtest,dc=example,dc=com
gidNumber: 1321
objectClass: posixGroup
memberUid: puser21
cn: puser21_grp1
 
# puser21_grp2, Pagingtest, example.com
dn: cn=puser21_grp2,ou=Pagingtest,dc=example,dc=com
gidNumber: 1322
objectClass: posixGroup
memberUid: puser21
cn: puser21_grp2
 
# puser21_grp3, Pagingtest, example.com
dn: cn=puser21_grp3,ou=Pagingtest,dc=example,dc=com
gidNumber: 1323
objectClass: posixGroup
memberUid: puser21
cn: puser21_grp3
 
# puser21_grp4, Pagingtest, example.com
dn: cn=puser21_grp4,ou=Pagingtest,dc=example,dc=com
gidNumber: 1324
objectClass: posixGroup
memberUid: puser21
cn: puser21_grp4
 
# puser21_grp5, Pagingtest, example.com
dn: cn=puser21_grp5,ou=Pagingtest,dc=example,dc=com
gidNumber: 1325
objectClass: posixGroup
memberUid: puser21
cn: puser21_grp5
 
# search result
search: 2
result: 0 Success
control: 1.2.840.113556.1.4.319 false MA0CAQAECNoLAAAAAAAA
pagedresults: cookie=2gsAAAAAAAA=
Press [size] Enter for the next {5|size} entries.
 
filter: (memberuid=puser21)
requesting: All userApplication attributes
# extended LDIF
#
# LDAPv3
# base <ou=Pagingtest,dc=example,dc=com> with scope subtree
# filter: (memberuid=puser21)
# requesting: ALL
# with pagedResults control: size=5
#
 
# search result
search: 3
result: 4 Size limit exceeded
 
# numResponses: 7
# numEntries: 5

4. Setup sssd with domain section as:
[domain/LDAP]
ldap_page_size = 5
id_provider = ldap
ldap_uri = ldap://openldap.example.com
ldap_search_base = ou=Pagingtest,dc=example,dc=com
debug_level = 0xFFF0
ldap_tls_cacert = /etc/openldap/certs/server.pem  


5. Verify using sssd if 5 objects are returned:
 
# id puser21
uid=1321(puser21) gid=1321(puser21_grp1) groups=1321(puser21_grp1)  <== Should have also returned puser1_[grp2,grp3,grp4,grp5]


Actual results:
initgroup doesn't return the data related to the first page. i.e. the first 5 groups.

Expected results:
sssd should return data for the pages that have been searched.

Additional info:
Log shows:
 
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_initgr_user] (0x4000): Process user's groups
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_initgr_rfc2307_next_base] (0x0400): Searching for groups with base [ou=Pagingtest,dc=example,dc=com]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(memberuid=puser21)(objectclass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberuid]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 4
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [cn=puser21_grp1,ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [cn=puser21_grp2,ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [cn=puser21_grp3,ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [cn=puser21_grp4,ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [cn=puser21_grp5,ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x18759d0], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x1000): Total count [0]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(memberuid=puser21)(objectclass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][ou=Pagingtest,dc=example,dc=com].
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberuid]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x1875c00], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x18736e0], connected[1], ops[0x1875c00], ldap[0x186a170]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Size limit exceeded(4), no errmsg set
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Size limit exceeded(4), no errmsg set
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_initgr_done] (0x4000): Initgroups done
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_get_initgr_done] (0x4000): Error in initgroups: [5][Input/output error]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_id_op_done] (0x4000): too many communication failures, giving up...
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [sdap_handle_release] (0x2000): Trace: sh[0x18736e0], connected[1], ops[(nil)], ldap[0x186a170], destructor_lock[0], release_memory[0]
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Fri May  4 12:54:52 2012) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 3,5,Init Groups Failed
(Fri May  4 12:54:54 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 1857730
Comment 2 Stephen Gallagher 2012-05-04 13:55:45 EDT
Upstream ticket:
https://fedorahosted.org/sssd/ticket/1322
Comment 3 RHEL Product and Program Management 2012-05-08 00:03:54 EDT
Since RHEL 6.3 External Beta has begun, and this bug remains
unresolved, it has been rejected as it is not proposed as
exception or blocker.

Red Hat invites you to ask your support representative to
propose this request, if appropriate and relevant, in the
next release of Red Hat Enterprise Linux.
Comment 6 Stephen Gallagher 2012-05-10 14:12:42 EDT
Patch is available upstream
Comment 10 Kaushik Banerjee 2012-05-16 06:42:15 EDT
Verified in version sssd-1.8.0-27


Output of automation run:
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
:: [   LOG    ] :: paging_control_007: maxpagesize=10,totalpageentries=5 on ldapserver & enumerate=false,ldap_page_size=5 in sssd. enumerate a user in 20 groups
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

:: [   PASS   ] :: Running '> /var/log/sssd/sssd_LDAP.log'
Stopping sssd: [  OK  ]
:: [   PASS   ] :: Running 'service sssd stop'
:: [   PASS   ] :: Running 'rm -fr /var/lib/sss/db/*.ldb'
Starting sssd: [  OK  ]
[  OK  ]
:: [   PASS   ] :: Running 'service sssd start'
:: [   PASS   ] :: napping for 5 secs...
:: [   PASS   ] :: Running 'restart_clearing_cache'
uid=1321(puser21) gid=1321(puser21_grp1) groups=1321(puser21_grp1),1324(puser21_grp4),1325(puser21_grp5),1322(puser21_grp2),1323(puser21_grp3)
:: [   PASS   ] :: Running 'id puser21 | tee /tmp/output21'
:: [   PASS   ] :: File '/tmp/output21' should contain 'puser21_grp1'
:: [   PASS   ] :: File '/tmp/output21' should contain 'puser21_grp5'
:: [   PASS   ] :: File '/tmp/output21' should not contain 'puser21_grp10'
puser21_grp1
:: [   PASS   ] :: Running 'id -gn puser21 | tee /tmp/output21_primarygroup'
:: [   PASS   ] :: File '/tmp/output21_primarygroup' should contain 'puser21_grp1'
(Tue May 15 15:18:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Tue May 15 15:18:52 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
:: [   PASS   ] :: Running 'cat /var/log/sssd/sssd_LDAP.log | grep -A 3 puser21_grp5 | grep "Search result: Success"'
spawn ssh -q -l puser21 localhost echo 'login successful'
puser21@localhost's password: 
Could not chdir to home directory /home/puser21: No such file or directory
login successful
:: [   PASS   ] :: Authentication successful, as expected
:: [   PASS   ] :: Running 'auth_success puser21 Secret123'
'02bd5bde-ffec-4b51-8d39-2529884042e4'
paging-control-007 result: PASS
Comment 11 Stephen Gallagher 2012-06-12 08:54:33 EDT
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
No documentation required
Comment 13 errata-xmlrpc 2012-06-20 07:56:55 EDT
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2012-0747.html

Note You need to log in before you can comment on or make changes to this bug.