openldap-bugs November 2013

openldap-bugs@openldap.org

18 participants
55 discussions

Re: (ITS#7743) bdb_idl_intersection() seems to expand the search candidates unnecessarily
by quanah＠zimbra.com 11 Nov '13

11 Nov '13

--On Tuesday, November 12, 2013 3:25 AM +0000 quanah(a)zimbra.com wrote: > --On Tuesday, November 12, 2013 3:09 AM +0000 > nishino-yoshinori(a)mxc.nes.nec.co.jp wrote: > >> Full_Name: Yoshinori Nishino >> Version: 2.4.37 >> OS: RedHatEL 5.5 >> URL: ftp://ftp.openldap.org/incoming/ >> Submission from: (NULL) (210.143.35.12) > > back-bdb is deprecated, I suggest you use back-mdb instead. Hm, I see the same bit exists for back-mdb too at line 720ish. Oh well. :P --Quanah -- Quanah Gibson-Mount Architect - Server Zimbra, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

Re: (ITS#7743) bdb_idl_intersection() seems to expand the search candidates unnecessarily
by quanah＠zimbra.com 11 Nov '13

11 Nov '13

--On Tuesday, November 12, 2013 3:09 AM +0000 nishino-yoshinori(a)mxc.nes.nec.co.jp wrote: > Full_Name: Yoshinori Nishino > Version: 2.4.37 > OS: RedHatEL 5.5 > URL: ftp://ftp.openldap.org/incoming/ > Submission from: (NULL) (210.143.35.12) back-bdb is deprecated, I suggest you use back-mdb instead. --Quanah -- Quanah Gibson-Mount Architect - Server Zimbra, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

(ITS#7743) bdb_idl_intersection() seems to expand the search candidates unnecessarily
by nishino-yoshinori＠mxc.nes.nec.co.jp 11 Nov '13

11 Nov '13

Full_Name: Yoshinori Nishino Version: 2.4.37 OS: RedHatEL 5.5 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (210.143.35.12) Dear sir, OS:Red Hat Enterprise Linux 5.5(x86) (2.6.18-194.el5) Version: 2.4.37 + BDB 4.4.20 In our environment, the issue occurs that the ldapsearch command using the following filter always took about 15`30 seconds. '(|(mailLocalAddress=XXXXXXX@xxxx.yy.zz)(mailRoutingAddress=XXXXXXX@xxxx.yy.zz)(&(xxxXXXXAlias=XXXXXXX)(xxxXXXYYYYYYList=bb)))' # masked the private information for the security reason. As far as I checked the debug.log("loglevel -1" in slapd.conf) and servers/slapd/back-bdb/idl.c, bdb_idl_intersection() seems to expand the search candidates unnecessarily, which results in this slow response. #Please see the log below(masked the private information for the security reason) The detail that I expect is as follows: == 1. By seaeching the index datebases, slapd got the candidate sets for each of the attributes. A.The candidate set of mailLocalAddress: (list-type: the number of elements=296, minID=296,maxID=858689) B.The candidate set of mailRoutingAddress:(list-type: the number of elements=0, minID=0,maxID=0) C.The candidate set of xxxXXXXAlias:(list-type: the number of elements=2, minID=676406, maxID=676407) D.The candidate set of xxxXXXYYYYYYList:(range-type: minID=628610, maxID=868129) #become range-type because the number of elements is more than 65536 2. First, slapd ran bdb_idl_intersection(C,D) according to the search filter, which resulted in the following candidate set. E.(range-type: minID=676406, maxID=676407) 3. Next, slapd ran bdb_idl_union(E,A), which resulted in the following. F.(range-type: minID=296, maxID=858689) 4. Finally, slapd ran bdb_idl_union(F,B), which resulted in the following search candidate. G.(range-type: minID=296, maxID=858689) Therefore, slapd searched many candidates unnecessarily. == The issues seems to occur because the following part of idl.c. 1087 /* If a range completely covers the list, the result is 1088 * just the list. If idmin to idmax is contiguous, just 1089 * turn it into a range. 1090 */ 1091 if ( BDB_IDL_IS_RANGE( b ) 1092 && BDB_IDL_RANGE_FIRST( b ) <= BDB_IDL_RANGE_FIRST( a ) 1093 && BDB_IDL_RANGE_LAST( b ) >= BDB_IDL_RANGE_LAST( a ) ) { 1094 if (idmax - idmin + 1 == a[0]) 1095 { 1096 a[0] = NOID; 1097 a[1] = idmin; 1098 a[2] = idmax; 1099 } 1100 goto done; 1101 } In the aforementioned "2", the set C matches the "if" condition of line 1094. Therefore the result of bdb_idl_intersection() becomes the range-type candidate set. If the set C didn't matche the condition, slapd would run "goto"(line 1094), according to which the result of bdb_idl_intersection(C,D) would be just "C"(list-type: the number of elements=2, minID=676406, maxID=676407). However, because the bdb_idl_intersection() make the result set changed into "range-type" unnecessarily, slapd is finally forced to search about 800,000 entries in vain. The response of the ldapsearch command becomes faster by modifying idl.c like that: 1087 /* If a range completely covers the list, the result is 1088 * just the list. If idmin to idmax is contiguous, just 1089 * turn it into a range. 1090 */ 1091 if ( BDB_IDL_IS_RANGE( b ) 1092 && BDB_IDL_RANGE_FIRST( b ) <= BDB_IDL_RANGE_FIRST( a ) 1093 && BDB_IDL_RANGE_LAST( b ) >= BDB_IDL_RANGE_LAST( a ) ) { 1094 /* if (idmax - idmin + 1 == a[0]) 1095 { 1096 a[0] = NOID; 1097 a[1] = idmin; 1098 a[2] = idmax; 1099 } */ 1100 goto done; 1101 } By the aforementioned modification, the search candidate set becomes (list-type: the number of elements=298, minID=296,maxID=858689). I think the line 1094-1099 part of idl.c seems to be a bug. The part seems to be implemented in order to just make "ids[]" smaller. If the reason is so, would you please consider fixing idl.c? *debug log(masked for security reason) Nov 12 10:42:58 server2 slapd[714]: daemon: activity on 1 descriptor Nov 12 10:42:58 server2 slapd[714]: daemon: activity on: Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: slap_listener_activate(8): Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=8 busy Nov 12 10:42:58 server2 slapd[714]: >>> slap_listener(ldap:///) Nov 12 10:42:58 server2 slapd[714]: daemon: listen=8, new connection on 10 Nov 12 10:42:58 server2 slapd[714]: daemon: added 10r (active) listener=(nil) Nov 12 10:42:58 server2 slapd[714]: conn=1000 fd=10 ACCEPT from IP=127.0.0.1:51095 (IP=0.0.0.0:389) Nov 12 10:42:58 server2 slapd[714]: daemon: activity on 2 descriptors Nov 12 10:42:58 server2 slapd[714]: daemon: activity on: Nov 12 10:42:58 server2 slapd[714]: 10r Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: daemon: read active on 10 Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: connection_get(10) Nov 12 10:42:58 server2 slapd[714]: connection_get(10): got connid=1000 Nov 12 10:42:58 server2 slapd[714]: connection_read(10): checking for input on id=1000 Nov 12 10:42:58 server2 slapd[714]: op tag 0x60, time 1384220578 Nov 12 10:42:58 server2 slapd[714]: daemon: activity on 1 descriptor Nov 12 10:42:58 server2 slapd[714]: daemon: activity on: Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=0 do_bind Nov 12 10:42:58 server2 slapd[714]: >>> dnPrettyNormal: <cn=XXXXXXXX> Nov 12 10:42:58 server2 slapd[714]: <<< dnPrettyNormal: <cn=XXXXXXXX>, <cn=XXXXXXXX> Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=0 BIND dn="cn=XXXXXXXX" method=128 Nov 12 10:42:58 server2 slapd[714]: do_bind: version=3 dn="cn=XXXXXXXX" method=128 Nov 12 10:42:58 server2 slapd[714]: ==> bdb_bind: dn: cn=XXXXXXXX Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=0 BIND dn="cn=XXXXXXXX" mech=SIMPLE ssf=0 Nov 12 10:42:58 server2 slapd[714]: do_bind: v3 bind: "cn=XXXXXXXX" to "cn=XXXXXXXX" Nov 12 10:42:58 server2 slapd[714]: send_ldap_result: conn=1000 op=0 p=3 Nov 12 10:42:58 server2 slapd[714]: send_ldap_result: err=0 matched="" text="" Nov 12 10:42:58 server2 slapd[714]: send_ldap_response: msgid=1 tag=97 err=0 Nov 12 10:42:58 server2 slapd[714]: daemon: activity on 1 descriptor Nov 12 10:42:58 server2 slapd[714]: daemon: activity on: Nov 12 10:42:58 server2 slapd[714]: 10r Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: daemon: read active on 10 Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=0 RESULT tag=97 err=0 text= Nov 12 10:42:58 server2 slapd[714]: connection_get(10) Nov 12 10:42:58 server2 slapd[714]: connection_get(10): got connid=1000 Nov 12 10:42:58 server2 slapd[714]: connection_read(10): checking for input on id=1000 Nov 12 10:42:58 server2 slapd[714]: op tag 0x63, time 1384220578 Nov 12 10:42:58 server2 slapd[714]: daemon: activity on 1 descriptor Nov 12 10:42:58 server2 slapd[714]: daemon: activity on: Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=1 do_search Nov 12 10:42:58 server2 slapd[714]: >>> dnPrettyNormal: <ou=People,dc=yyyy,dc=zz> Nov 12 10:42:58 server2 slapd[714]: <<< dnPrettyNormal: <ou=People,dc=yyyy,dc=zz>, <ou=people,dc=yyyy,dc=zz> Nov 12 10:42:58 server2 slapd[714]: SRCH "ou=People,dc=yyyy,dc=zz" 2 0 Nov 12 10:42:58 server2 slapd[714]: 0 0 0 Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: OR Nov 12 10:42:58 server2 slapd[714]: begin get_filter_list Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: AND Nov 12 10:42:58 server2 slapd[714]: begin get_filter_list Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: begin get_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: end get_filter_list Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: end get_filter_list Nov 12 10:42:58 server2 slapd[714]: end get_filter 0 Nov 12 10:42:58 server2 slapd[714]: filter: (|(mailLocalAddress=XXXXXXX@xxxx.yy.zz)(mailRoutingAddress=XXXXXXX@xxxx.yy.zz)(&(xxxXXXXAlias=XXXXXXX)(xxxXXXYYYYYYList=bb))) Nov 12 10:42:58 server2 slapd[714]: attrs: Nov 12 10:42:58 server2 slapd[714]: Nov 12 10:42:58 server2 slapd[714]: conn=1000 op=1 SRCH base="ou=People,dc=yyyy,dc=zz" scope=2 deref=0 filter="(|(mailLocalAddress=XXXXXXX@xxxx.yy.zz)(mailRoutingAddress=XXXXXXX@xxxx.yy.zz)(&(xxxXXXXAlias=XXXXXXX)(xxxXXXYYYYYYList=bb)))" Nov 12 10:42:58 server2 slapd[714]: => bdb_search Nov 12 10:42:58 server2 slapd[714]: bdb_dn2entry("ou=people,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x1 Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x2 Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("ou=people,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x19 Nov 12 10:42:58 server2 slapd[714]: entry_decode: "ou=People,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(ou=People,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "ou=People,dc=yyyy,dc=zz" "entry" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: search_candidates: base="ou=people,dc=yyyy,dc=zz" (0x00000019) scope=2 Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2idl("ou=people,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: @ou=people,dc=yyyy,dc=zz Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2idl: id=-1 first=25 last=868130 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: AND Nov 12 10:42:58 server2 slapd[714]: => bdb_list_candidates 0xa0 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: OR Nov 12 10:42:58 server2 slapd[714]: => bdb_list_candidates 0xa1 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => bdb_equality_candidates (objectClass) Nov 12 10:42:58 server2 slapd[714]: => key_read Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: [b49d1940] Nov 12 10:42:58 server2 slapd[714]: <= bdb_index_read: failed (-30989) Nov 12 10:42:58 server2 slapd[714]: <= bdb_equality_candidates: id=0, first=0, last=0 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=0 first=0 last=0 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: OR Nov 12 10:42:58 server2 slapd[714]: => bdb_list_candidates 0xa1 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => bdb_equality_candidates (mailLocalAddress) Nov 12 10:42:58 server2 slapd[714]: => key_read Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: [6d316d9b] Nov 12 10:42:58 server2 slapd[714]: <= bdb_index_read 296 candidates Nov 12 10:42:58 server2 slapd[714]: <= bdb_equality_candidates: id=296, first=296, last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=296 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => bdb_equality_candidates (mailRoutingAddress) Nov 12 10:42:58 server2 slapd[714]: => key_read Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: [0afa05dc] Nov 12 10:42:58 server2 slapd[714]: <= bdb_index_read: failed (-30989) Nov 12 10:42:58 server2 slapd[714]: <= bdb_equality_candidates: id=0, first=0, last=0 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=0 first=0 last=0 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: AND Nov 12 10:42:58 server2 slapd[714]: => bdb_list_candidates 0xa0 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => bdb_equality_candidates (xxxXXXXAlias) Nov 12 10:42:58 server2 slapd[714]: => key_read Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: [a0867a62] Nov 12 10:42:58 server2 slapd[714]: <= bdb_index_read 2 candidates Nov 12 10:42:58 server2 slapd[714]: <= bdb_equality_candidates: id=2, first=676406, last=676407 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=2 first=676406 last=676407 Nov 12 10:42:58 server2 slapd[714]: => bdb_filter_candidates Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => bdb_equality_candidates (xxxXXXYYYYYYList) Nov 12 10:42:58 server2 slapd[714]: => key_read Nov 12 10:42:58 server2 slapd[714]: bdb_idl_fetch_key: [d752aaac] Nov 12 10:42:58 server2 slapd[714]: <= bdb_index_read 239520 candidates Nov 12 10:42:58 server2 slapd[714]: <= bdb_equality_candidates: id=-1, first=628610, last=868129 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=-1 first=628610 last=868129 Nov 12 10:42:58 server2 slapd[714]: <= bdb_list_candidates: id=-1 first=676406 last=676407 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=-1 first=676406 last=676407 Nov 12 10:42:58 server2 slapd[714]: <= bdb_list_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_list_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_list_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: <= bdb_filter_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: bdb_search_candidates: id=-1 first=296 last=858689 Nov 12 10:42:58 server2 slapd[714]: entry_decode: "mailRoutingAddress=000000130(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(mailRoutingAddress=100000130(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("mailRoutingAddress=000000130(a)xxxx-xxxxx.yyyy.zz,ou=people,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x128 Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: OR Nov 12 10:42:58 server2 slapd[714]: => test_filter_or Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000130(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "mailLocalAddress" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000130(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "mailRoutingAddress" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: AND Nov 12 10:42:58 server2 slapd[714]: => test_filter_and Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000130(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "xxxXXXXAlias" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter_and 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter_or 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: bdb_search: 296 does not match filter Nov 12 10:42:58 server2 slapd[714]: entry_decode: "gecos=000000130(a)xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(gecos=000000130(a)xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("ou=ftp,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x24 Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("gecos=000000130(a)xxxx-xxxxx.yyyy.zz,ou=ftp,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x129 Nov 12 10:42:58 server2 slapd[714]: bdb_search: 297 scope not okay Nov 12 10:42:58 server2 slapd[714]: entry_decode: "mailRoutingAddress=000000131(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(mailRoutingAddress=100000131(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("mailRoutingAddress=000000131(a)xxxx-xxxxx.yyyy.zz,ou=people,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x12a Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: OR Nov 12 10:42:58 server2 slapd[714]: => test_filter_or Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000131(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "mailLocalAddress" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000131(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "mailRoutingAddress" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: AND Nov 12 10:42:58 server2 slapd[714]: => test_filter_and Nov 12 10:42:58 server2 slapd[714]: => test_filter Nov 12 10:42:58 server2 slapd[714]: EQUALITY Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access to "mailRoutingAddress=100000131(a)xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" "xxxXXXXAlias" requested Nov 12 10:42:58 server2 slapd[714]: <= root access granted Nov 12 10:42:58 server2 slapd[714]: => access_allowed: search access granted by manage(=mwrscxd) Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter_and 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter_or 5 Nov 12 10:42:58 server2 slapd[714]: <= test_filter 5 Nov 12 10:42:58 server2 slapd[714]: bdb_search: 298 does not match filter Nov 12 10:42:58 server2 slapd[714]: entry_decode: "gecos=000000131(a)xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(gecos=000000131(a)xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("gecos=000000131(a)xxxx-xxxxx.yyyy.zz,ou=ftp,dc=yyyy,dc=zz") Nov 12 10:42:58 server2 slapd[714]: <= bdb_dn2id: got id=0x12b Nov 12 10:42:58 server2 slapd[714]: bdb_search: 299 scope not okay (omitted) Best Regards,

1 0

(ITS#7742) New: PBKDF2 module for OpenLDAP
by hamano＠osstech.co.jp 08 Nov '13

08 Nov '13

Full_Name: HAMANO Tsukasa Version: git master OS: Linux URL: ftp://ftp.openldap.org/incoming/0001-New-PBKDF2-module.patch Submission from: (NULL) (240b:10:2640:bf0:c1b8:b6c9:76f:8964) PBKDF2(RFC 2898) suport for OpenLDAP See README for details. -- The attached patch file is derived from OpenLDAP Software. All of the modifications to OpenLDAP Software represented in the following patch(es) were developed by HAMANO Tsukasa <hamano(a)osstech.co.jp>. I have not assigned rights and/or interest in this work to any party. Copyright 2013 HAMANO Tsukasa <hamano(a)osstech.co.jp> Redistribution and use in source and binary forms, with or without modification, are permitted only as authorized by the OpenLDAP Public License.

1 0

Re: (ITS#7741) Incorrect indexing of entryDN
by hyc＠symas.com 06 Nov '13

06 Nov '13

raphael.ouazana(a)linagora.com wrote: > Full_Name: Raphael Ouazana > Version: 2.4.26 > OS: Linux > URL: ftp://ftp.openldap.org/incoming/ > Submission from: (NULL) (88.173.78.196) > > > Hi, > > I have a pretty big database (hdb, 300 000 entries) with low memory (1/4 GB). > If I try a search with scope sub, base dc=suffix, and filter > (entryDN=uid=nonexisting,dc=people,dc=suffix), the search is very slow (I > stopped after some minutes). > But if I try with scope base, base uid=nonexisting,dc=people,dc=suffix, filter > (objectClass=*), the result is immediate, telling there is no such entry. > > I have read that since 2.4.13 entryDN is indexed by dn2id, but it doesn't seem > to be the case. Only positive results from the index were being used. > Regards, > Raphaël Ouazana. > > PS : my test database run OpenLDAP 2.4.26 only, but I have not seen any change > in the area of entryDN indexing. Will try with 2.4.37 if you think something has > changed. Nothing has changed in this section of code in 5 years. Fixed now in master. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: (ITS#7741) Incorrect indexing of entryDN
by quanah＠zimbra.com 06 Nov '13

06 Nov '13

--On Wednesday, November 06, 2013 4:27 PM +0000 raphael.ouazana(a)linagora.com wrote: > Full_Name: Raphael Ouazana > Version: 2.4.26 > OS: Linux > URL: ftp://ftp.openldap.org/incoming/ > Submission from: (NULL) (88.173.78.196) > > > Hi, > > I have a pretty big database (hdb, 300 000 entries) with low memory (1/4 > GB). If I try a search with scope sub, base dc=suffix, and filter > (entryDN=uid=nonexisting,dc=people,dc=suffix), the search is very slow (I > stopped after some minutes). > But if I try with scope base, base uid=nonexisting,dc=people,dc=suffix, > filter (objectClass=*), the result is immediate, telling there is no such > entry. What makes you feel there is a bug present? Nothing in your report indicates the presence of a bug. --Quanah -- Quanah Gibson-Mount Architect - Server Zimbra, Inc. -------------------- Zimbra :: the leader in open source messaging and collaboration

1 0

(ITS#7741) Incorrect indexing of entryDN
by raphael.ouazana＠linagora.com 06 Nov '13

06 Nov '13

Full_Name: Raphael Ouazana Version: 2.4.26 OS: Linux URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (88.173.78.196) Hi, I have a pretty big database (hdb, 300 000 entries) with low memory (1/4 GB). If I try a search with scope sub, base dc=suffix, and filter (entryDN=uid=nonexisting,dc=people,dc=suffix), the search is very slow (I stopped after some minutes). But if I try with scope base, base uid=nonexisting,dc=people,dc=suffix, filter (objectClass=*), the result is immediate, telling there is no such entry. I have read that since 2.4.13 entryDN is indexed by dn2id, but it doesn't seem to be the case. Regards, Raphaël Ouazana. PS : my test database run OpenLDAP 2.4.26 only, but I have not seen any change in the area of entryDN indexing. Will try with 2.4.37 if you think something has changed.

1 0

Re: (ITS#7739) Include of include badly handled while converting from slapd.conf to slapd.d
by hyc＠symas.com 05 Nov '13

05 Nov '13

Raphaël Ouazana-Sustowski wrote: > Hi, > > Le 04/11/2013 17:06, Howard Chu a écrit : >> raphael.ouazana(a)linagora.com wrote: >>> Full_Name: Raphael Ouazana >>> Version: 2.4.37 >>> OS: Linux >>> URL: ftp://ftp.openldap.org/incoming/ >>> Submission from: (NULL) (88.173.78.196) >>> >>> >>> Hi, >>> >>> If I have for example a main slapd.conf with: >>> include <path>schema.conf >>> >>> And a simple schema.conf: >>> include <path>core.schema >>> include <path>cosine.schema >>> include <path>inetorgperson.schema >>> >>> When I try to convert slapd.conf to slapd.d with slaptest, the >>> resulting >>> configuration is incorrect: the schema file are not included. >>> >> >> Try again, using a different name than "schema.conf" > > It doesn't work neither. > > Steps to reproduce: > > 1. basic slapd.conf, but: > a. replace include <schemapath>core.schema by include > <configpath>morethings.conf > b. add index sn eq at the end > > 2. create <configpath>morethings.conf including only > <schemapath>core.schema Fixed now in master. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: (ITS#7740) back-meta lock threads when remote node is unreachable
by hyc＠symas.com 05 Nov '13

05 Nov '13

jorge.perez.burgos(a)ericsson.com wrote: > Full_Name: Jorge Perez Burgos > Version: 2.4.35 > OS: SLES 11 > URL: ftp://ftp.openldap.org/incoming/0001-Don-t-lock-other-threads-while-trying-… > Submission from: (NULL) (195.235.15.243) > > > When there is meta proxy traffic to another node and this node becomes > unreachable the thread in meta retrying to connect to the remote node locks all > the other threads making the slapd unresponsive until the timeout expires. > Attach a possible fix > ftp://ftp.openldap.org/incoming/0001-Don-t-lock-other-threads-while-trying-… > > and a backtraceo of some threads when the problem happens: Thanks, the patch looks OK, committed to git master. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

(ITS#7740) back-meta lock threads when remote node is unreachable
by jorge.perez.burgos＠ericsson.com 05 Nov '13

05 Nov '13

Full_Name: Jorge Perez Burgos Version: 2.4.35 OS: SLES 11 URL: ftp://ftp.openldap.org/incoming/0001-Don-t-lock-other-threads-while-trying-… Submission from: (NULL) (195.235.15.243) When there is meta proxy traffic to another node and this node becomes unreachable the thread in meta retrying to connect to the remote node locks all the other threads making the slapd unresponsive until the timeout expires. Attach a possible fix ftp://ftp.openldap.org/incoming/0001-Don-t-lock-other-threads-while-trying-… and a backtraceo of some threads when the problem happens: Thread 259 (Thread 0x7ff9a771e700 (LWP 27085)): #0 0x00007ff9fc2a6294 in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007ff9fc2a1619 in _L_lock_1008 () from /lib64/libpthread.so.0 #2 0x00007ff9fc2a142e in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00000000004b6007 in meta_back_search (op=0x31a8800, rs=0x7ff9a771d930) at search.c:2012 #4 0x000000000043ab31 in fe_op_search (op=0x31a8800, rs=0x7ff9a771d930) at search.c:402 #5 0x00000000004a0ef7 in overlay_op_walk (op=0x31a8800, rs=0x7ff9a771d930, which=op_search, oi=0x87cc000, on=0x0) at backover.c:671 #6 0x00000000004a1970 in over_op_func (op=0x31a8800, rs=0x7ff9a771bdc8, which=op_bind) at backover.c:723 #7 0x000000000043b37c in do_search (op=0x31a8800, rs=0x7ff9a771d930) at search.c:247 #8 0x0000000000437eef in connection_operation (ctx=0x7ff9a771db30, arg_v=<optimized out>) at connection.c:1313 #9 0x0000000000438b1b in connection_read_thread (ctx=0x7ff9a771db30, argv=<optimized out>) at connection.c:1449 #10 0x00000000004ee750 in ldap_int_thread_pool_wrapper (xpool=<optimized out>) at tpool.c:688 #11 0x00007ff9fc29f7b6 in start_thread () from /lib64/libpthread.so.0 #12 0x00007ff9fbffac5d in clone () from /lib64/libc.so.6 #13 0x0000000000000000 in ?? () 226 Transfer complete (unique file name:0001-Don-t-lock-other-threads-while-trying-to-connect-to.patch). Thread 258 (Thread 0x7ff9a6f1d700 (LWP 27086)): #0 0x00007ff9fbff1786 in poll () from /lib64/libc.so.6 #1 0x0000000000504b19 in ldap_int_poll (ld=0x5f03e030, s=462, tvp=0x7ff9a6f1afd0, wr=<optimized out>) at os-ip.c:302 #2 0x0000000000505248 in ldap_pvt_connect (async=<optimized out>, addrlen=<optimized out>, sin=<optimized out>, s=<optimized out>, ld=<optimized out>) at os-ip.c:465 #3 ldap_connect_to_host (ld=0x5f03e030, sb=0x592c0ed0, proto=1, srv=0x6e26edc0, async=0) at os-ip.c:658 #4 0x00000000004ef4d7 in ldap_int_open_connection (ld=0x5f03e030, conn=0x574bfc20, srv=0x6e26edc0, async=0) at open.c:367 #5 0x000000000050243a in ldap_new_connection (ld=0x5f03e030, srvlist=0x6cf79598, use_ldsb=1, connect=<optimized out>, bind=0x0, m_req=0, m_res=0) at request.c:481 #6 0x00000000004ef41f in ldap_open_defconn (ld=0x7ff9a6f1aef0) at open.c:41 #7 0x0000000000503158 in ldap_send_initial_request (ld=0x5f03e030, msgtype=<optimized out>, dn=<optimized out>, ber=0x6db20780, msgid=1) at request.c:130 #8 0x00000000004f8ebc in ldap_sasl_bind (ld=0x5f03e030, dn=0x89e9660 <error reading variable>, mechanism=0x0, cred=0x7ff9a6f1b220, sctrls=0x0, cctrls=<optimized out>, msgidp=0x7ff9a6f1b248) at sasl.c:148 #9 0x00000000004cb270 in meta_back_proxy_authz_bind (mc=0x12165ba0, candidate=2, op=0x342ac00, rs=0x7ff9a6f1ca60, sendok=LDAP_BACK_SENDERR, dolock=0) at bind.c:1582 #10 0x00000000004cb49f in meta_back_single_dobind (op=0x342ac00, rs=0x7ff9a6f1ca60, mcp=0x7ff9a6f1b560, candidate=2, sendok=LDAP_BACK_SENDERR, nretries=<optimized out>, dolock=0) at bind.c:605 #11 0x00000000004d5df3 in meta_back_retry (op=0x342ac00, rs=0x7ff9a6f1ca60, mcp=0x7ff9a6f1b560, candidate=2, sendok=LDAP_BACK_SENDERR) at conn.c:766 #12 0x00000000004b42c5 in meta_back_modify (op=0x342ac00, rs=0x7ff9a6f1ca60) at modify.c:194 #13 0x00000000004506d8 in fe_op_modify (op=0x342ac00, rs=0x7ff9a6f1ca60) at modify.c:303 #14 0x00000000004a0ef7 in overlay_op_walk (op=0x342ac00, rs=0x7ff9a6f1ca60, which=op_modify, oi=0x87cc000, on=0x0) at backover.c:671 #15 0x00000000004a1970 in over_op_func (op=0x342ac00, rs=0x7ff9a6f1a918, which=4000) at backover.c:723 #16 0x0000000000451007 in do_modify (op=0x342ac00, rs=0x7ff9a6f1ca60) at modify.c:177 #17 0x0000000000437eef in connection_operation (ctx=0x7ff9a6f1cb30, arg_v=<optimized out>) at connection.c:1313 #18 0x00000000004ee750 in ldap_int_thread_pool_wrapper (xpool=<optimized out>) at tpool.c:688 #19 0x00007ff9fc29f7b6 in start_thread () from /lib64/libpthread.so.0 #20 0x00007ff9fbffac5d in clone () from /lib64/libc.so.6 #21 0x0000000000000000 in ?? () Thread 257 (Thread 0x7ff9a671c700 (LWP 27088)): #0 0x00007ff9fc2a6294 in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007ff9fc2a1619 in _L_lock_1008 () from /lib64/libpthread.so.0 #2 0x00007ff9fc2a142e in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00000000004d4540 in meta_back_getconn (op=0x46fe000, rs=0x7ff9a671b930, candidate=0x0, sendok=LDAP_BACK_SENDERR) at conn.c:1129 #4 0x00000000004b5b61 in meta_back_search (op=0x46fe000, rs=0x7ff9a671b930) at search.c:803 #5 0x000000000043ab31 in fe_op_search (op=0x46fe000, rs=0x7ff9a671b930) at search.c:402 #6 0x00000000004a0ef7 in overlay_op_walk (op=0x46fe000, rs=0x7ff9a671b930, which=op_search, oi=0x87cc000, on=0x0) at backover.c:671 #7 0x00000000004a1970 in over_op_func (op=0x46fe000, rs=0x0, which=op_bind) at backover.c:723 #8 0x000000000043b37c in do_search (op=0x46fe000, rs=0x7ff9a671b930) at search.c:247 #9 0x0000000000437eef in connection_operation (ctx=0x7ff9a671bb30, arg_v=<optimized out>) at connection.c:1313 #10 0x0000000000438b1b in connection_read_thread (ctx=0x7ff9a671bb30, argv=<optimized out>) at connection.c:1449 #11 0x00000000004ee750 in ldap_int_thread_pool_wrapper (xpool=<optimized out>) at tpool.c:688 #12 0x00007ff9fc29f7b6 in start_thread () from /lib64/libpthread.so.0 #13 0x00007ff9fbffac5d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? () Thread 256 (Thread 0x7ff9a5f1b700 (LWP 27089)): #0 0x00007ff9fc2a6294 in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007ff9fc2a1619 in _L_lock_1008 () from /lib64/libpthread.so.0 #2 0x00007ff9fc2a142e in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00000000004d4540 in meta_back_getconn (op=0x46f5000, rs=0x7ff9a5f1a930, candidate=0x0, sendok=LDAP_BACK_SENDERR) at conn.c:1129 #4 0x00000000004b5b61 in meta_back_search (op=0x46f5000, rs=0x7ff9a5f1a930) at search.c:803 #5 0x000000000043ab31 in fe_op_search (op=0x46f5000, rs=0x7ff9a5f1a930) at search.c:402 #6 0x00000000004a0ef7 in overlay_op_walk (op=0x46f5000, rs=0x7ff9a5f1a930, which=op_search, oi=0x87cc000, on=0x0) at backover.c:671 #7 0x00000000004a1970 in over_op_func (op=0x46f5000, rs=0x0, which=op_bind) at backover.c:723 #8 0x000000000043b37c in do_search (op=0x46f5000, rs=0x7ff9a5f1a930) at search.c:247 #9 0x0000000000437eef in connection_operation (ctx=0x7ff9a5f1ab30, arg_v=<optimized out>) at connection.c:1313 #10 0x0000000000438b1b in connection_read_thread (ctx=0x7ff9a5f1ab30, argv=<optimized out>) at connection.c:1449 #11 0x00000000004ee750 in ldap_int_thread_pool_wrapper (xpool=<optimized out>) at tpool.c:688 #12 0x00007ff9fc29f7b6 in start_thread () from /lib64/libpthread.so.0 #13 0x00007ff9fbffac5d in clone () from /lib64/libc.so.6 #14 0x0000000000000000 in ?? ()

1 0

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-bugs November 2013