[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
(ITS#7743) bdb_idl_intersection() seems to expand the search candidates unnecessarily
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,