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@xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(mailRoutingAddress=100000130@xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("mailRoutingAddress=000000130@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@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@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@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@xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(gecos=000000130@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@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@xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(mailRoutingAddress=100000131@xxxx-xxxxx.yyyy.zz,ou=People,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("mailRoutingAddress=000000131@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@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@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@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@xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz" Nov 12 10:42:58 server2 slapd[714]: <= entry_decode(gecos=000000131@xxxx-xxxxx.yyyy.zz,ou=Ftp,dc=yyyy,dc=zz) Nov 12 10:42:58 server2 slapd[714]: => bdb_dn2id("gecos=000000131@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,
--On Tuesday, November 12, 2013 3:09 AM +0000 nishino-yoshinori@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
--On Tuesday, November 12, 2013 3:25 AM +0000 quanah@zimbra.com wrote: > --On Tuesday, November 12, 2013 3:09 AM +0000 > nishino-yoshinori@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
nishino-yoshinori@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) > > > 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. > 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? This is certainly no bug in idl_intersection(), it is an optimization that makes subsequent intersection operations faster. As such, your suggested fix is wrong. If you want to suggest a fix, you should look at idl_union() instead. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/
Dear Quanah, Thank you for your prompt reply. > back-bdb is deprecated, I suggest you use back-mdb instead. Would you tell me why you recommend using back-mdb? It's because the collision of the hash key in the bdb index occurs more easily than in the mdb index? Best Regards, -- ********************************************* Yoshinori Nishino NEC Soft, Ltd. E-MAIL: nishino-yoshinori@mxc.nes.nec.co.jp *********************************************
Dear Howard, Thank you for your prompt reply. >This is certainly no bug in idl_intersection(), it is an >optimizatio that makes subsequent intersection operations faster. >As such, your suggested fix is wrong. I understood the line 1094-1099 part of idl.c was implemented to optimize subsequent intersection oprations. On the other hands, in this case, bdb_idl_intersection(C,D) (as I described before) returns the range-type candidate set despite its having only two elements. Then, by subsequent bdb_idl_union() with A (list-type: the number of elements=296, minID=296,maxID=858689), the candidate set becomes very huge. #bdb_idl_union() seems to change the candidate set into "range-type" #if one of the two sets is a "range-type". The impact of removing the optimization of bdb_idl_intersection() is only that subsequent bdb_idl_intersection() oprations become slower in certain cases? If the aforementioned optimization becomes effective when the number of the element is more than certain threshold number(ex.1024), I would like to change bdb_idl_intersection() like that: ex) 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] && a[0] > 1024) 1095 { 1096 a[0] = NOID; 1097 a[1] = idmin; 1098 a[2] = idmax; 1099 } 1100 goto done; 1101 } The issue occurs in the environment of our user and makes some trouble because of the slow response of the ldapsearch. So, I would like to find some fix of the issue. >If you want to suggest a fix, you should look at idl_union() instead. Thank you for your advice. I'll also try to check bdb_idl_union(). If you have other good idea to fix the issue, could you let me know? Best Regards, -- ********************************************* Yoshinori Nishino NEC Soft, Ltd. E-MAIL: nishino-yoshinori@mxc.nes.nec.co.jp *********************************************
moved from Incoming to Software Bugs
Needs to be examined in the context of back-mdb, which has identical code in idl.c
*** This issue has been marked as a duplicate of issue 8868 ***