Sync Replication issues with bindmethod=simple

["Michael Cassaniti" <m.cassaniti@gmail.com>]

Hi,
I have followed the OpenLDAP v2.3 Software Administrators Guide to
using Sync Replication. I have the following snippets for my LDAP
servers.

[provider]
overlay syncprov
syncprov-checkpoint 10 60
syncprov-sessionlog 100

[consumer]
syncrepl rid=101
       provider=ldap://192.168.0.4
       type=refreshOnly
       interval=00:00:30:00
       retry="05 +"
       searchbase="dc=home,dc=net"
       bindmethod=simple
       binddn="uid=ldap,ou=Users,dc=home,dc=net"
       credentials=secret

I have checked that I can authenticate using simple authentication as
user ldap (via ldapwhoami) against the sync provider server. This was
successful. I also know that the credentials information, which is in
SSHA form is correct.

The problem is that there is a bind issue. In particular it returns
the following error in the log on the consumer: do_syncrep1:
ldap_sasl_bind_s failed (49)

On the provider, there is not much information to determine the error.
I extracted the following:
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on 1 descriptor
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on:
Feb 24 22:13:14 Home-Server4 slapd[3749]:
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: listen=7, new connection on 12
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: added 12r (active)
listener=(nil)
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on 1 descriptor
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on:
Feb 24 22:13:14 Home-Server4 slapd[3749]:  12r
Feb 24 22:13:14 Home-Server4 slapd[3749]:
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: read active on 12
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:13:14 Home-Server4 slapd[3749]: => access_allowed: auth
access to "uid=ldap,ou=Users,dc=home,dc=net" "userPassword" requested
Feb 24 22:13:14 Home-Server4 slapd[3749]: => acl_get: [1] attr userPassword
Feb 24 22:13:14 Home-Server4 slapd[3749]: => slap_access_allowed: no
res from state (userPassword)
Feb 24 22:13:14 Home-Server4 slapd[3749]: => acl_mask: access to entry
"uid=ldap,ou=Users,dc=home,dc=net", attr "userPassword" requested
Feb 24 22:13:14 Home-Server4 slapd[3749]: => acl_mask: to value by "", (=0)
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= check a_dn_pat: self
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= check a_dn_pat:
cn=root,dc=home,dc=net
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= check a_dn_pat:
uid=ldap,ou=users,dc=home,dc=net
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= check a_dn_pat: anonymous
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= acl_mask: [4] applying
auth(=xd) (stop)
Feb 24 22:13:14 Home-Server4 slapd[3749]: <= acl_mask: [4] mask: auth(=xd)
Feb 24 22:13:14 Home-Server4 slapd[3749]: => slap_access_allowed: auth
access granted by auth(=xd)
Feb 24 22:13:14 Home-Server4 slapd[3749]: => access_allowed: auth
access granted by auth(=xd)
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on 1 descriptor
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on:
Feb 24 22:13:14 Home-Server4 slapd[3749]:  12r
Feb 24 22:13:14 Home-Server4 slapd[3749]:
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: read active on 12
Feb 24 22:13:14 Home-Server4 slapd[3749]: connection_read(12): input
error=-2 id=0, closing.
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on 1 descriptor
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: activity on:
Feb 24 22:13:14 Home-Server4 slapd[3749]:
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:13:14 Home-Server4 slapd[3749]: daemon: removing 12

I don't think, though I could be wrong, that this has anything to do
with poor ACLs being set. I also tried the bind using the rootdn, but
this also failed. The output log from the provider gave the
folllowing:
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on 1 descriptor
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on:
Feb 24 22:16:03 Home-Server4 slapd[4083]:
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: listen=7, new connection on 12
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: added 12r (active)
listener=(nil)
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on 1 descriptor
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on:
Feb 24 22:16:03 Home-Server4 slapd[4083]:  12r
Feb 24 22:16:03 Home-Server4 slapd[4083]:
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: read active on 12
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on 1 descriptor
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on:
Feb 24 22:16:03 Home-Server4 slapd[4083]:  12r
Feb 24 22:16:03 Home-Server4 slapd[4083]:
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: read active on 12
Feb 24 22:16:03 Home-Server4 slapd[4083]: connection_read(12): input
error=-2 id=0, closing.
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on 1 descriptor
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: activity on:
Feb 24 22:16:03 Home-Server4 slapd[4083]:
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: epoll: listen=7
active_threads=1 tvp=zero
Feb 24 22:16:03 Home-Server4 slapd[4083]: daemon: removing 12

As you can see, none of this is very forthcoming for information. Log
level is set to 28904, so there should be a high amount of logging
done to show any/all errors. Modifying the ACLs on the provider to:
access to * by * write still returned this error.

What suprises me is that this is an SASL error, when SASL is not used
for a simple bind. Like I have already stated, this is a configuration
straight from the OpenLDAP Guide, so what have I done wrong.