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,