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)}" ":"