You're right about the rootdn so I should be able to bind to my LDAP and pretty much read/write anything to it. I think I should provide a bit more background to what I'm trying to do here.
We are using a role management tool called Grouper to create groups. These groups are then populated with users. Subsequently, separate applications may use these groups to track an individual's role, or to determine which users are authorized to access the resource.
Grouper also comes with a provisioning functionality whereby these groups are provisioned over to LDAP server. The groups that are provisioned over will also contain the users that are members of these groups.
What we would like to happen is for the groups to be provisioned from Grouper to LDAP with the following entry in LDAP:
dn: cn=ncl:staff,ou=grouper,dc=ncl,dc=ac,dc=uk objectClass: groupOfNames objectClass: top member: uid=john.smith@ncl.ac.uk,ou=people,dc=ncl,dc=ac,dc=uk cn: ncl:staff
The above entry tells us that we have John Smith (uid=john.smith@ncl.ac.uk) in the Staff group. The Staff group was created by Grouper and John Smith was already a member of the Staff group.
The way our Grouper configuration is setup is we have the all the users under "ou=people,dc=ncl,dc=ac,dc=uk". The groups are provisioned to "ou=grouper,dc=ncl,dc=ac,dc=uk". So "ou=grouper,dc=ncl,dc=ac,dc=uk" starts off empty before any provisioning activity. After the completion of provisioning, a samply entry (shown above) should be found under "ou=grouper,dc=ncl,dc=ac,dc=uk".
However, nothing is being provisioned over as described in my previous email. I believe its an openLDAP issue cos I've pretty much exhausted my Grouper options. I don't think its an ACL issue cos I'm binding as rootDN and so I should be able to read/write to "ou=grouper,dc=ncl,dc=ac,dc=uk".
I did a "slap -d acl" and what I got is shown below:
slapd -d acl @(#) $OpenLDAP: slapd 2.3.27 (Jan 3 2007 13:11:16) $
brewbuilder@ls20-bc1-14.build.redhat.com:/builddir/build/BUILD/openldap- 2.3.27/openldap-2.3.27/build-servers/servers/slapd daemon: bind(7) failed errno=98 (Address already in use) daemon: bind(7) failed errno=98 (Address already in use) slapd stopped. connections_destroy: nothing to destroy.
And when I do a "lsof -i :389",
[root@pen openldap]# lsof -i :389 COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME slapd 19048 ldap 7u IPv6 2005549 TCP *:ldap (LISTEN) slapd 19048 ldap 8u IPv4 2005550 TCP *:ldap (LISTEN)
I can't tell if this is an error or not. My LDAP server seems to be working fine so the "Address already in use" error shouldn't be popping up. From what I gather while trawling through the mailing lists, this could be an Ipv6 issue. Is this indeed the case?
The logs (set at loglevel=256) is given below when I try to run the provisioning program. Any help would be greatly appreciated. Cheers.
Regards Sanjay
Nov 2 11:15:06 pen slapd[18902]: conn=6 fd=12 ACCEPT from IP=128.240.2.3:43541 (IP=0.0.0.0:389) Nov 2 11:15:06 pen slapd[18902]: conn=6 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Nov 2 11:15:06 pen slapd[18902]: conn=6 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Nov 2 11:15:06 pen slapd[18902]: conn=6 op=0 RESULT tag=97 err=0 text= Nov 2 11:15:06 pen slapd[18902]: conn=7 fd=13 ACCEPT from IP=128.240.2.3:51570 (IP=0.0.0.0:389) Nov 2 11:15:06 pen slapd[18902]: conn=7 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Nov 2 11:15:06 pen slapd[18902]: conn=7 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Nov 2 11:15:06 pen slapd[18902]: conn=7 op=0 RESULT tag=97 err=0 text= Nov 2 11:15:06 pen slapd[18902]: conn=7 op=1 UNBIND Nov 2 11:15:06 pen slapd[18902]: conn=7 fd=13 closed Nov 2 11:15:07 pen slapd[18902]: conn=8 fd=13 ACCEPT from IP=128.240.2.3:48240 (IP=0.0.0.0:389) Nov 2 11:15:07 pen slapd[18902]: conn=8 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Nov 2 11:15:07 pen slapd[18902]: conn=8 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Nov 2 11:15:07 pen slapd[18902]: conn=8 op=0 RESULT tag=97 err=0 text= Nov 2 11:15:07 pen slapd[18902]: conn=8 op=1 SRCH base="ou=people,dc=ncl,dc=ac,dc=uk" scope=2 deref=3 filter="(&(uid=groupersystem)(objectClass=eduPerson))" Nov 2 11:15:07 pen slapd[18902]: conn=8 op=1 SRCH attr=cn cn uid Nov 2 11:15:07 pen slapd[18902]: conn=8 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= Nov 2 11:15:07 pen slapd[18902]: conn=8 op=2 UNBIND Nov 2 11:15:07 pen slapd[18902]: conn=8 fd=13 closed Nov 2 11:15:07 pen slapd[18902]: conn=6 op=1 UNBIND Nov 2 11:15:07 pen slapd[18902]: conn=6 fd=12 closed
-----Original Message----- From: Aaron Richton [mailto:richton@nbcs.rutgers.edu] Sent: 29 October 2007 18:47 To: Sanjay Vivek Cc: openldap-software@openldap.org Subject: Re: LDAP provisioning error.
It looks like you're binding as the rootdn (therefore access rules don't apply). Furthermore, you've got two log messages regarding "access granted" and none regarding denials. "does not match filter" seems to be your issue, your statement that they "should match" aside.
What makes you think this is an ACL issue? Does it change for rootdn vs. non-root?
If you want to debug ACLs, try slapd -d acl to make it easier to read.
What does slapcat(8) show for these entries in question?
You're searching on edupersonprincipalname, but you don't seem to have an index present there. You probably should...
On Mon, 29 Oct 2007, Sanjay Vivek wrote:
Hello everyone,
I'm involved in a project whereby access groups (with users) are provisioned to a LDAP server. In a nutshell, the groups should be provisioned under ""ou=groups,dc=ncl,dc=ac,dc=uk" while the users in each group are found in ""ou=people,dc=ncl,dc=ac,dc=uk".
However, the
groups are not being provisioned over to our LDAP server. Among the dubious looking lines in the log files include:
bdb_search: 134 does not match filter
(the above entry should match the filter. And similiarly for other entries)
I'm guessing this has something to do with the ACL control list in slapd.conf. The relevant section in slapd.conf is given below:
# Allow anyone to write and read to ou=people access to dn.one="ou=people,dc=ncl,dc=ac,dc=uk" attr=children by anonymous read by anonymous write
# Allow anyone to write and read to ou=grouper access to dn.one="ou=grouper,dc=ncl,dc=ac,dc=uk" attr=children by anonymous read by anonymous write
So basically what the above configuration is meant to do is that anyone can read or write to one level below both people and
grouper. I
realise this is highly insecure but it's merely for testing purposes.
Any suggestions or help would be greatly appreciated. The complete logs of this transaction is given below. Thanks again.
Cheers Sanjay
Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1
descriptor Oct
16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: listen=8, new connection on 13 Oct 16 15:13:34 pen slapd[9559]: daemon: added 13r Oct 16
15:13:34
pen slapd[9559]: conn=8 fd=13 ACCEPT from IP=128.240.2.3:51855 (IP=0.0.0.0:389) Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: 13r Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: read active on 13 Oct 16 15:13:34 pen slapd[9559]: connection_get(13) Oct 16 15:13:34 pen slapd[9559]: connection_get(13): got connid=8 Oct 16 15:13:34 pen slapd[9559]: connection_read(13): checking for input on id=8 Oct 16 15:13:34 pen slapd[9559]: ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable) Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16
15:13:34 pen
slapd[9559]: daemon: select: listen=8 active_threads=0
tvp=NULL Oct 16
15:13:34 pen slapd[9559]: do_bind Oct 16 15:13:34 pen
slapd[9559]: >>>
dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:34 pen slapd[9559]: <<< dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk>, <cn=manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:34 pen slapd[9559]: do_bind: version=3 dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:34 pen slapd[9559]: conn=8 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:34 pen slapd[9559]: ==> bdb_bind: dn: cn=Manager,dc=ncl,dc=ac,dc=uk Oct 16 15:13:34 pen slapd[9559]: conn=8 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Oct 16 15:13:34 pen slapd[9559]: do_bind: v3 bind: "cn=Manager,dc=ncl,dc=ac,dc=uk" to "cn=Manager,dc=ncl,dc=ac,dc=uk" Oct 16 15:13:34 pen slapd[9559]: send_ldap_result: conn=8
op=0 p=3 Oct
16 15:13:34 pen slapd[9559]: send_ldap_result: err=0 matched="" text="" Oct 16 15:13:34 pen slapd[9559]: send_ldap_response: msgid=1 tag=97 err=0 Oct 16 15:13:34 pen slapd[9559]: conn=8 op=0 RESULT
tag=97 err=0
text= Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: listen=8, new connection on 15 Oct 16 15:13:34 pen slapd[9559]: daemon: added 15r Oct 16
15:13:34
pen slapd[9559]: conn=9 fd=15 ACCEPT from IP=128.240.2.3:36766 (IP=0.0.0.0:389) Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: 15r Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: read active on 15 Oct 16 15:13:34 pen slapd[9559]: connection_get(15) Oct 16 15:13:34 pen slapd[9559]: connection_get(15): got connid=9 Oct 16 15:13:34 pen slapd[9559]: connection_read(15): checking for input on id=9 Oct 16 15:13:34 pen slapd[9559]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable) Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16
15:13:34 pen
slapd[9559]: daemon: select: listen=8 active_threads=0
tvp=NULL Oct 16
15:13:34 pen slapd[9559]: do_bind Oct 16 15:13:34 pen
slapd[9559]: >>>
dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:34 pen slapd[9559]: <<< dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk>, <cn=manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:34 pen slapd[9559]: do_bind: version=3 dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:34 pen slapd[9559]: conn=9 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:34 pen slapd[9559]: ==> bdb_bind: dn: cn=Manager,dc=ncl,dc=ac,dc=uk Oct 16 15:13:34 pen slapd[9559]: conn=9 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Oct 16 15:13:34 pen slapd[9559]: do_bind: v3 bind: "cn=Manager,dc=ncl,dc=ac,dc=uk" to "cn=Manager,dc=ncl,dc=ac,dc=uk" Oct 16 15:13:34 pen slapd[9559]: send_ldap_result: conn=9
op=0 p=3 Oct
16 15:13:34 pen slapd[9559]: send_ldap_result: err=0 matched="" text="" Oct 16 15:13:34 pen slapd[9559]: send_ldap_response: msgid=1 tag=97 err=0 Oct 16 15:13:34 pen slapd[9559]: conn=9 op=0 RESULT
tag=97 err=0
text= Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: 15r Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: read active on 15 Oct 16 15:13:34 pen slapd[9559]: connection_get(15) Oct 16 15:13:34 pen slapd[9559]: connection_get(15): got connid=9 Oct 16 15:13:34 pen slapd[9559]: connection_read(15): checking for input on id=9 Oct 16 15:13:34 pen slapd[9559]: ber_get_next on fd 15 failed errno=0 (Success) Oct 16 15:13:34 pen slapd[9559]: connection_read(15): input error=-2 id=9, closing. Oct 16 15:13:34 pen slapd[9559]: connection_closing: readying conn=9 sd=15 for close Oct 16 15:13:34 pen slapd[9559]: connection_close: deferring conn=9 sd=15 Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:34 pen slapd[9559]: daemon: activity on: Oct 16 15:13:34 pen slapd[9559]: Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:34 pen slapd[9559]: do_unbind Oct 16 15:13:34 pen slapd[9559]: conn=9 op=1 UNBIND Oct 16 15:13:34 pen slapd[9559]: connection_resched:
attempting
closing conn=9 sd=15 Oct 16 15:13:34 pen slapd[9559]: connection_close: conn=9
sd=15 Oct 16
15:13:34 pen slapd[9559]: daemon: removing 15 Oct 16 15:13:34 pen slapd[9559]: conn=9 fd=15 closed Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: listen=8, new connection on 15 Oct 16 15:13:35 pen slapd[9559]: daemon: added 15r Oct 16
15:13:35
pen slapd[9559]: conn=10 fd=15 ACCEPT from IP=128.240.2.3:50097 (IP=0.0.0.0:389) Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: 15r Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: read active on 15 Oct 16 15:13:35 pen slapd[9559]: connection_get(15) Oct 16 15:13:35 pen slapd[9559]: connection_get(15): got connid=10 Oct 16 15:13:35 pen slapd[9559]: connection_read(15): checking for input on id=10 Oct 16 15:13:35 pen slapd[9559]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable) Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16
15:13:35 pen
slapd[9559]: daemon: select: listen=8 active_threads=0
tvp=NULL Oct 16
15:13:35 pen slapd[9559]: do_bind Oct 16 15:13:35 pen
slapd[9559]: >>>
dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:35 pen slapd[9559]: <<< dnPrettyNormal: <cn=Manager,dc=ncl,dc=ac,dc=uk>, <cn=manager,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:35 pen slapd[9559]: do_bind: version=3 dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:35 pen slapd[9559]: conn=10 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" method=128 Oct 16 15:13:35 pen slapd[9559]: ==> bdb_bind: dn: cn=Manager,dc=ncl,dc=ac,dc=uk Oct 16 15:13:35 pen slapd[9559]: conn=10 op=0 BIND dn="cn=Manager,dc=ncl,dc=ac,dc=uk" mech=SIMPLE ssf=0 Oct 16 15:13:35 pen slapd[9559]: do_bind: v3 bind: "cn=Manager,dc=ncl,dc=ac,dc=uk" to "cn=Manager,dc=ncl,dc=ac,dc=uk" Oct 16 15:13:35 pen slapd[9559]: send_ldap_result: conn=10 op=0 p=3 Oct 16 15:13:35 pen slapd[9559]: send_ldap_result: err=0 matched="" text="" Oct 16 15:13:35 pen slapd[9559]: send_ldap_response: msgid=1 tag=97 err=0 Oct 16 15:13:35 pen slapd[9559]: conn=10 op=0 RESULT tag=97 err=0 text= Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: 15r Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: read active on 15 Oct 16 15:13:35 pen slapd[9559]: connection_get(15) Oct 16 15:13:35 pen slapd[9559]: connection_get(15): got connid=10 Oct 16 15:13:35 pen slapd[9559]: connection_read(15): checking for input on id=10 Oct 16 15:13:35 pen slapd[9559]: ber_get_next on fd 15 failed errno=11 (Resource temporarily unavailable) Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16
15:13:35 pen
slapd[9559]: daemon: select: listen=8 active_threads=0
tvp=NULL Oct 16
15:13:35 pen slapd[9559]: do_search Oct 16 15:13:35 pen slapd[9559]:
dnPrettyNormal:
<ou=people,dc=ncl,dc=ac,dc=uk> Oct 16 15:13:35 pen slapd[9559]: <<< dnPrettyNormal: <ou=people,dc=ncl,dc=ac,dc=uk>,
<ou=people,dc=ncl,dc=ac,dc=uk> Oct 16
15:13:35 pen slapd[9559]: SRCH "ou=people,dc=ncl,dc=ac,dc=uk" 2 3 Oct 16 15:13:35 pen slapd[9559]: 0 0 0 Oct 16 15:13:35 pen slapd[9559]: begin get_filter Oct 16
15:13:35 pen
slapd[9559]: AND Oct 16 15:13:35 pen slapd[9559]: begin get_filter_list Oct 16 15:13:35 pen slapd[9559]: begin
get_filter Oct
16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen
slapd[9559]:
end get_filter 0 Oct 16 15:13:35 pen slapd[9559]: begin
get_filter Oct
16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen
slapd[9559]:
end get_filter 0 Oct 16 15:13:35 pen slapd[9559]: end
get_filter_list
Oct 16 15:13:35 pen slapd[9559]: end get_filter 0 Oct 16 15:13:35 pen slapd[9559]: filter: (&(eduPersonPrincipalName=groupersystem)(objectClass=eduPerson)) Oct 16 15:13:35 pen slapd[9559]: => get_ctrls Oct 16 15:13:35 pen slapd[9559]: => get_ctrls: oid="2.16.840.1.113730.3.4.2" (noncritical) Oct 16 15:13:35 pen slapd[9559]: <= get_ctrls: n=1 rc=0 err="" Oct 16 15:13:35 pen slapd[9559]: attrs: Oct 16 15:13:35 pen slapd[9559]: cn Oct 16 15:13:35 pen slapd[9559]: cn Oct 16 15:13:35 pen slapd[9559]: eduPersonPrincipalName Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: conn=10 op=1 SRCH base="ou=people,dc=ncl,dc=ac,dc=uk" scope=2 deref=3
filter="(&(eduPersonPrincipalName=groupersystem)(objectClass=eduPerson
)) " Oct 16 15:13:35 pen slapd[9559]: conn=10 op=1 SRCH attr=cn cn eduPersonPrincipalName Oct 16 15:13:35 pen slapd[9559]: slap_global_control: unavailable control: 2.16.840.1.113730.3.4.2 Oct 16 15:13:35 pen slapd[9559]: => bdb_search Oct 16 15:13:35 pen slapd[9559]: bdb_dn2entry("ou=people,dc=ncl,dc=ac,dc=uk") Oct 16 15:13:35 pen slapd[9559]: search_candidates: base="ou=people,dc=ncl,dc=ac,dc=uk" (0x0000004d) scope=2 Oct 16 15:13:35 pen slapd[9559]: => bdb_filter_candidates Oct 16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen slapd[9559]: => bdb_equality_candidates (objectClass) Oct 16 15:13:35 pen slapd[9559]: => key_read Oct 16 15:13:35 pen slapd[9559]: bdb_idl_fetch_key: [01872a84] Oct 16 15:13:35 pen slapd[9559]: <= bdb_index_read: failed (-30989) Oct 16 15:13:35 pen slapd[9559]: <= bdb_equality_candidates: id=0, first=0,
last=0 Oct 16
15:13:35 pen slapd[9559]: <= bdb_filter_candidates: id=0 first=0 last=0 Oct 16 15:13:35 pen slapd[9559]: => bdb_dn2idl("ou=people,dc=ncl,dc=ac,dc=uk") Oct 16 15:13:35 pen slapd[9559]: bdb_idl_fetch_key: @ou=people,dc=ncl,dc=ac,dc=uk Oct 16 15:13:35 pen slapd[9559]: <= bdb_dn2idl: id=9
first=77 last=135
Oct 16 15:13:35 pen slapd[9559]: => bdb_filter_candidates Oct 16 15:13:35 pen slapd[9559]: AND Oct 16 15:13:35 pen slapd[9559]: => bdb_list_candidates 0xa0 Oct 16 15:13:35 pen slapd[9559]: => bdb_filter_candidates Oct 16 15:13:35 pen slapd[9559]: AND Oct 16 15:13:35 pen slapd[9559]: => bdb_list_candidates 0xa0 Oct 16 15:13:35 pen slapd[9559]: => bdb_filter_candidates Oct 16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen slapd[9559]: => bdb_equality_candidates (eduPersonPrincipalName) Oct 16 15:13:35 pen slapd[9559]: <= bdb_equality_candidates: (eduPersonPrincipalName) index_param failed (18) Oct 16 15:13:35 pen slapd[9559]: <= bdb_filter_candidates: id=-1 first=1 last=135 Oct 16 15:13:35 pen slapd[9559]: => bdb_filter_candidates Oct 16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen slapd[9559]: => bdb_equality_candidates (objectClass) Oct 16 15:13:35 pen slapd[9559]: => key_read Oct 16 15:13:35 pen slapd[9559]: bdb_idl_fetch_key: [aef9a643] Oct 16 15:13:35 pen slapd[9559]: <= bdb_index_read 8 candidates Oct 16 15:13:35 pen slapd[9559]: <= bdb_equality_candidates: id=8, first=128,
last=135 Oct
16 15:13:35 pen slapd[9559]: <= bdb_filter_candidates: id=8 first=128 last=135 Oct 16 15:13:35 pen slapd[9559]: <= bdb_list_candidates: id=-1 first=128 last=135 Oct 16 15:13:35 pen slapd[9559]: <= bdb_filter_candidates: id=-1 first=128 last=135 Oct 16 15:13:35 pen slapd[9559]: <= bdb_list_candidates: id=8 first=128 last=135 Oct 16 15:13:35 pen slapd[9559]: <= bdb_filter_candidates: id=8 first=128 last=135 Oct 16 15:13:35 pen slapd[9559]: bdb_search_candidates: id=8
first=128
last=135 Oct 16 15:13:35 pen slapd[9559]: => test_filter Oct 16 15:13:35 pen slapd[9559]: AND Oct 16 15:13:35 pen slapd[9559]: => test_filter_and Oct 16 15:13:35 pen slapd[9559]: => test_filter Oct 16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen slapd[9559]: => access_allowed: search access to "uid=gene.wilder@hotmail.com,ou=people,dc=ncl,dc=ac,dc=uk" "eduPersonPrincipalName" requested Oct 16 15:13:35 pen slapd[9559]: <= root access granted Oct 16 15:13:35 pen slapd[9559]: <= test_filter 5 Oct 16 15:13:35 pen slapd[9559]: <= test_filter_and 5 Oct 16 15:13:35 pen
slapd[9559]: <=
test_filter 5 Oct 16 15:13:35 pen slapd[9559]: bdb_search: 128 does not match filter Oct 16 15:13:35 pen slapd[9559]: => test_filter Oct 16 15:13:35 pen slapd[9559]: AND Oct 16 15:13:35 pen slapd[9559]: => test_filter_and Oct 16 15:13:35 pen slapd[9559]: => test_filter Oct 16 15:13:35 pen slapd[9559]: EQUALITY Oct 16 15:13:35 pen slapd[9559]: => access_allowed: search access to "uid=lionel.messi@hotmail.com,ou=people,dc=ncl,dc=ac,dc=uk" "eduPersonPrincipalName" requested Oct 16 15:13:35 pen slapd[9559]: <= root access granted Oct 16 15:13:35 pen slapd[9559]: <= test_filter 5 Oct 16 15:13:35 pen slapd[9559]: <= test_filter_and 5 Oct 16 15:13:35 pen
slapd[9559]: <=
test_filter 5 Oct 16 15:13:35 pen slapd[9559]: bdb_search: 135 does not match filter Oct 16 15:13:35 pen slapd[9559]: send_ldap_result: conn=10 op=1 p=3 Oct 16 15:13:35 pen slapd[9559]: send_ldap_result: err=0 matched="" text="" Oct 16 15:13:35 pen slapd[9559]: send_ldap_response: msgid=2 tag=101 err=0 Oct 16 15:13:35 pen slapd[9559]: conn=10 op=1 SEARCH RESULT tag=101 err=0 nentries=0 text= Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: 15r Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: read active on 15 Oct 16 15:13:35 pen slapd[9559]: connection_get(15) Oct 16 15:13:35 pen slapd[9559]: connection_get(15): got connid=10 Oct 16 15:13:35 pen slapd[9559]: connection_read(15): checking for input on id=10 Oct 16 15:13:35 pen slapd[9559]: ber_get_next on fd 15 failed errno=0 (Success) Oct 16 15:13:35 pen slapd[9559]: connection_read(15): input error=-2 id=10, closing. Oct 16 15:13:35 pen slapd[9559]: connection_closing: readying conn=10 sd=15 for close Oct 16 15:13:35 pen slapd[9559]: connection_close: deferring conn=10 sd=15 Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: do_unbind Oct 16 15:13:35 pen slapd[9559]: conn=10 op=2 UNBIND Oct 16 15:13:35 pen slapd[9559]: connection_resched:
attempting
closing conn=10 sd=15 Oct 16 15:13:35 pen slapd[9559]: connection_close: conn=10 sd=15 Oct 16 15:13:35 pen slapd[9559]: daemon: removing 15 Oct 16 15:13:35 pen slapd[9559]: conn=10 fd=15 closed Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: 13r Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: read active on 13 Oct 16 15:13:35 pen slapd[9559]: connection_get(13) Oct 16 15:13:35 pen slapd[9559]: connection_get(13): got connid=8 Oct 16 15:13:35 pen slapd[9559]: connection_read(13): checking for input on id=8 Oct 16 15:13:35 pen slapd[9559]: ber_get_next on fd 13 failed errno=11 (Resource temporarily unavailable) Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16
15:13:35 pen
slapd[9559]: daemon: select: listen=8 active_threads=0
tvp=NULL Oct 16
15:13:35 pen slapd[9559]: do_unbind Oct 16 15:13:35 pen slapd[9559]: conn=8 op=1 UNBIND Oct 16 15:13:35 pen slapd[9559]: connection_closing: readying conn=8 sd=13 for close Oct 16 15:13:35 pen slapd[9559]: connection_resched: attempting closing conn=8 sd=13 Oct 16 15:13:35 pen slapd[9559]: connection_close: conn=8
sd=13 Oct 16
15:13:35 pen slapd[9559]: daemon: removing 13 Oct 16 15:13:35 pen slapd[9559]: conn=8 fd=13 closed Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: 13r Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: read active on 13 Oct 16 15:13:35 pen slapd[9559]: connection_get(13) Oct 16 15:13:35 pen slapd[9559]: connection_get(13): connection not used Oct 16 15:13:35 pen slapd[9559]: connection_read(13): no connection! Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: activity on 1 descriptor Oct 16 15:13:35 pen slapd[9559]: daemon: activity on: Oct 16 15:13:35 pen slapd[9559]: Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=7 active_threads=0 tvp=NULL Oct 16 15:13:35 pen slapd[9559]: daemon: select: listen=8 active_threads=0 tvp=NULL
Regards
Sanjay Vivek Middleware Team ISS University of Newcastle Upon Tyne