Hi, thank you for reading this message!
I'm configuring openldap (2.4.26) as a proxy for active directory (Win 2003) and encountered some inconsistent responses to bind/search requests that may relate to a misconfiguration around an rwm mapping. Hopefully this is the right place to ask for this kind of assistance. I haven't yet been able to see what I'm missing but have spent a lot of time with slapd.conf man, slap-rwm man, and tailing logs even at loglevel -1. Here's what happens:
On the console of the openldap server, I'll start the slapd service like: ./slapd -4 -n slapd-ldap -u ldap -g ldap then run an ldapsearch command to the openldap server using a bindDN that requires no rewrite, and a base that requires a rewrite. I get successful binds and search results 100% of the time. If I then run an ldapsearch where the bindDN requires a rewrite, occasionally I'll get a "bind massage" error on the console. Tailing the log file, shows a line like this:
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 op=0 SEARCH RESULT tag=101 err=1 nentries=0 text=00000000: LdapErr: DSID-0C090627, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, vece
If I stop slapd, restart the service, and run the ldapsearch where the bindDN requires a rewrite, I'll only get errors. Then if I do an ldapsearch with a bindDN that doesn't need a rewrite (which always binds and searches successfully), subsequent ldapsearch bind/search attempts with a bindDN that requires a rewrite will succeed most of the time.
Below I've included some shell interaction and log output (loglevel 256 for brevity), non-comment lines from my slapd.conf, and other configuration details.
Any suggestions for how I could debug this further or glaring mistakes would be greatly appreciated.
Humbly yours,
Dave
# Start openldap
Aug 1 16:38:42 localhost slapd-ldap[19426]: @(#) $OpenLDAP: slapd 2.4.26 (Jul 29 2011 14:11:30) $#012#011dave@localhost.localdomain:/usr/src/openldap-2.4.26/servers/sla pd
Aug 1 16:38:42 localhost slapd-ldap[19427]: slapd starting
# bind and search that requires no rewrite on bind but a rewrite on base (ou=App Auth 1 -> ou=Students) - this always works
/opt/openldap/proxy/bin/ldapsearch -b "ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" -D "CN=Addott, Steven (saddott),ou=Students,DC=TEST_STUDENT,DC=TEST_EDU" -w "saddott" -x "(mail=sadd*)" name
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 fd=8 ACCEPT from IP=127.0.0.1:36499 (IP=0.0.0.0:389)
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" method=128
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" mech=SIMPLE ssf=0
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=0 RESULT tag=97 err=0 text=
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=1 SRCH base="ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=sadd*)"
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=1 SRCH attr=name
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 op=2 UNBIND
Aug 1 16:40:01 localhost slapd-ldap[19427]: conn=1001 fd=8 closed
# success! this comes back in the console:
# extended LDIF
#
# LDAPv3
# base <ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU> with scope subtree
# filter: (mail=sadd*)
# requesting: name
#
# Addott\2C Steven (saddott), Students, TEST_STUDENT.TEST_EDU
dn: cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU
name: Addott, Steven (saddott)
# search result
search: 2
result: 0 Success
# numResponses: 2
# numEntries: 1
# now search and bind requiring a search base rewrite and bind rewrite (mail -> cn)
/opt/openldap/proxy/bin/ldapsearch -b "ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" -D "mail=saddott@localhost.localdomain,ou=Students,DC=TEST_STUDENT,DC=TEST_ EDU" -w "saddott" -x "(mail=sadd*)" name
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 fd=8 ACCEPT from IP=127.0.0.1:36502 (IP=0.0.0.0:389)
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=0 BIND dn="mail=saddott@localhost.localdomain,ou=Students,dc=TEST_STUDENT,dc=TE ST_EDU" method=128
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 fd=12 ACCEPT from IP=127.0.0.1:36503 (IP=0.0.0.0:389)
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 op=0 SRCH base="ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=saddott@localhost.localdomain)"
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 op=0 SRCH attr=1.1
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 op=1 UNBIND
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1003 fd=12 closed
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" mech=SIMPLE ssf=0
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=0 RESULT tag=97 err=0 text=
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=1 SRCH base="ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=sadd*)"
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=1 SRCH attr=name
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 op=2 UNBIND
Aug 1 16:40:59 localhost slapd-ldap[19427]: conn=1002 fd=8 closed
# and again, success! this comes back
# extended LDIF
#
# LDAPv3
# base <ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU> with scope subtree
# filter: (mail=sadd*)
# requesting: name
#
# Addott\2C Steven (saddott), Students, TEST_STUDENT.TEST_EDU
dn: cn=Addott\2C Steven (saddott),ou=Students
# restarting the service
Aug 1 16:44:54 localhost slapd-ldap[19427]: daemon: shutdown requested and initiated.
Aug 1 16:44:54 localhost slapd-ldap[19427]: slapd shutdown: waiting for 0 operations/tasks to finish
Aug 1 16:44:54 localhost slapd-ldap[19427]: slapd stopped.
Aug 1 16:45:02 localhost slapd-ldap[19489]: @(#) $OpenLDAP: slapd 2.4.26 (Jul 29 2011 14:11:30) $#012#011dave@localhost.localdomain:/usr/src/openldap-2.4.26/servers/sla pd
Aug 1 16:45:02 localhost slapd-ldap[19490]: slapd starting
# here's where I get a failure, attempting to bind where the bind requires a rewrite
# same request as above but this time I'm doing it right after a service restart
[root@localhost openldap]# /opt/openldap/proxy/bin/ldapsearch -b "ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" -D "mail=saddott@localhost.localdomain,ou=Students,DC=TEST_STUDENT,DC=TEST_ EDU" -w "saddott" -x "(mail=sadd*)" name
ldap_bind: Other (e.g., implementation specific) error (80)
additional info: bindDN massage error
.. log file shows
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1000 fd=8 ACCEPT from IP=127.0.0.1:46174 (IP=0.0.0.0:389)
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1000 op=0 BIND dn="mail=saddott@localhost.localdomain,ou=Students,dc=TEST_STUDENT,dc=TE ST_EDU" method=128
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 fd=10 ACCEPT from IP=127.0.0.1:46175 (IP=0.0.0.0:389)
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 op=0 SRCH base="ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=saddott@localhost.localdomain)"
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 op=0 SRCH attr=1.1
Aug 1 16:45:12 localhost slapd-ldap[19490]: ==> rewrite_context_apply error ...
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1000 op=0 RESULT tag=97 err=80 text=bindDN massage error
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 op=0 SEARCH RESULT tag=101 err=1 nentries=0 text=00000000: LdapErr: DSID-0C090627, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, vece
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1000 fd=8 closed (connection lost)
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 op=1 UNBIND
Aug 1 16:45:12 localhost slapd-ldap[19490]: conn=1001 fd=10 closed
Now back to the request that required no bind rewrite
[root@localhost openldap]# /opt/openldap/proxy/bin/ldapsearch -b "ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" -D "CN=Addott, Steven (saddott),ou=Students,DC=TEST_STUDENT,DC=TEST_EDU" -w "saddott" -x "(mail=sadd*)" name
# extended LDIF
#
# LDAPv3
# base <ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU> with scope subtree
# filter: (mail=sadd*)
# requesting: name
#
# Addott\2C Steven (saddott), Students, TEST_STUDENT.TEST_EDU
dn: cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU
name: Addott, Steven (saddott)
# search result
search: 2
result: 0 Success
# numResponses: 2
# numEntries: 1
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 fd=8 ACCEPT from IP=127.0.0.1:46177 (IP=0.0.0.0:389)
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" method=128
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" mech=SIMPLE ssf=0
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=0 RESULT tag=97 err=0 text=
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=1 SRCH base="ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=sadd*)"
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=1 SRCH attr=name
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 op=2 UNBIND
Aug 1 16:45:47 localhost slapd-ldap[19490]: conn=1002 fd=8 closed
and searching again with the bindDN requiring a map rewrite - this time it failed
[root@localhost openldap]# /opt/openldap/proxy/bin/ldapsearch -b "ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_KSC" -D "mail=saddott@localhost.localdomain,ou=Students,DC=TEST_STUDENT,DC=TEST_ EDU" -w "saddott" -x "(mail=sadd*)" name
ldap_bind: Other (e.g., implementation specific) error (80)
additional info: bindDN massage error
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1003 fd=8 ACCEPT from IP=127.0.0.1:46180 (IP=0.0.0.0:389)
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1003 op=0 BIND dn="mail=saddott@localhost.localdomain,ou=Students,dc=TEST_STUDENT,dc=TE ST_EDU" method=128
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 fd=13 ACCEPT from IP=127.0.0.1:46181 (IP=0.0.0.0:389)
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 op=0 SRCH base="ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=saddott@localhost.localdomain)"
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 op=0 SRCH attr=1.1
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 op=0 SEARCH RESULT tag=101 err=1 nentries=0 text=00000000: LdapErr: DSID-0C090627, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, vece
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 op=1 UNBIND
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1004 fd=13 closed
Aug 1 16:45:56 localhost slapd-ldap[19490]: ==> rewrite_context_apply error ...
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1003 op=0 RESULT tag=97 err=80 text=bindDN massage error
Aug 1 16:45:56 localhost slapd-ldap[19490]: conn=1003 fd=8 closed (connection lost)
I tried the same ldapsearch command again and this time it succeeded
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 fd=8 ACCEPT from IP=127.0.0.1:46182 (IP=0.0.0.0:389)
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=0 BIND dn="mail=saddott@localhost.localdomain,ou=Students,dc=TEST_STUDENT,dc=TE ST_EDU" method=128
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 fd=13 ACCEPT from IP=127.0.0.1:46183 (IP=0.0.0.0:389)
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 op=0 SRCH base="ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=saddott@localhost.localdomain)"
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 op=0 SRCH attr=1.1
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 op=1 UNBIND
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1006 fd=13 closed
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=0 BIND dn="cn=Addott\2C Steven (saddott),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" mech=SIMPLE ssf=0
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=0 RESULT tag=97 err=0 text=
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=1 SRCH base="ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU" scope=2 deref=0 filter="(mail=sadd*)"
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=1 SRCH attr=name
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 op=2 UNBIND
Aug 1 16:46:12 localhost slapd-ldap[19490]: conn=1005 fd=8 closed
AD is running on a VM
openldap-2.4.26 was configured on a Fedora 15 (2.6.38.8-35.fc15.i686) VM with:
./configure --prefix=/opt/openldap/proxy --enable-ldap --enable-rewrite --enable-rwm --enable-memberof --with-tls=no
non-comment lines from my slapd.conf look like:
include /opt/openldap/proxy/etc/openldap/schema/core.schema
include /opt/openldap/proxy/etc/openldap/schema/cosine.schema
include /opt/openldap/proxy/etc/openldap/schema/inetorgperson.schema
# schema to add sAMAccountName
include /opt/openldap/proxy/etc/openldap/schema/myorg.schema
pidfile /opt/openldap/proxy/var/run/slapd.pid
argsfile /opt/openldap/proxy/var/run/slapd.args
moduleload rwm.la
#######################################################################
# BDB database definitions
#######################################################################
database ldap
suffix "dc=TEST_STUDENT,dc=TEST_EDU"
uri "ldap://..."
# ... is the ip of my AD host
acl-bind bindmethod=simple
binddn="cn=serviceuser,cn=Users,dc=TEST_STUDENT,dc=TEST_EDU"
credentials="pwd"
idassert-bind bindmethod=simple
binddn="cn=serviceuser,cn=Users,dc=TEST_STUDENT,dc=TEST_EDU"
credentials="pwd"
authzID="dn:cn=serviceuser,cn=Users,dc=TEST_STUDENT,dc=TEST_EDU"
loglevel 256
# much of this was borrowed from slapo-rwm man page
overlay rwm
rwm-rewriteEngine on
# all dataflow from client to server referring to DNs
rwm-rewriteContext default
rwm-rewriteRule "(.+,)?<virtualnamingcontext>$" "$1<realnamingcontext>" ":"
# empty filter
rwm-rewriteContext searchFilter
# from server to client
rwm-rewriteContext searchEntryDN
rwm-rewriteRule "(.+,)?<realnamingcontext>$" "$1<virtualnamingcontext>" ":"
rwm-rewriteContext searchAttrDN alias searchEntryDN
rwm-rewriteContext matchedDN alias searchEntryDN
# misc empty rules
rwm-rewriteContext referralAttrDN
rwm-rewriteContext referralDN
# define default rewrite for virtual of anything
# ou=App Auth 1 -> ou=Students
rwm-rewriteContext searchDN
rwm-rewriteRule "(.+)?ou=App Auth 1,dc=TEST_STUDENT,dc=TEST_EDU$" "$1ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" ":"
# bind map from source
rwm-rewriteMap ldap source2dn "ldap:///ou=Students,dc=TEST_STUDENT,dc=TEST_EDU?dn?sub"
rwm-rewriteContext bindDN
rwm-rewriteRule "^mail=([^,]*),ou=Students,dc=TEST_STUDENT,dc=TEST_EDU" "${source2dn(mail=$1)}" ":"