1 Topic by tedcox

  • tedcox
  • Member
  • Offline
  • Registered: 2012-06-06
  • Posts: 19

Topic: LDAP Replication Fails

==== Required information ====
- iRedMail version: 0.8.3
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): LDAP
- Linux/BSD distribution name and version: CentOS 5.8 (master)/6.3 (slave)
- Related log if you're reporting an issue:
====

Hello again,

Now that I have the new backup mail server running nicely, I'm back to trying to get LDAP to replicate.  I have searched exhaustively through the OpenLDAP docs, and what can be found online about making LDAP replicate on various distributions, and sadly it looks like there are a lot of variables at work.  However, I think I'm very close!  I have the machines talking to one another, I just can't get them to actually sync.

The master is a CentOS 5.8 i686 machine upgraded from iRedMail 0.7.0 to 0.8.3, the slave is a CentOS 6.3 x64 machine running a clean install of iRedMail 0.8.3.  I'm sure I'm just missing something simple here.  Thanks for the help!

Ted

The error message is:

do_syncrep2: rid=101 got search entry without Sync State control

I know the systems can talk to one another.  From the slave I can issue:

# ldapsearch -H ldaps://ldap-master.mydomain.com  -x -D cn=replicator,dc=mydomain,dc=com -W 
Enter LDAP Password: 
# extended LDIF
#
# LDAPv3
# base <dc=mydomain,dc=com> (default) with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# mydomain.com
dn: dc=mydomain,dc=com
objectClass: dcObject
objectClass: organization
dc: heroesinc
o: heroesinc

# domains, mydomain.com
dn: o=domains,dc=mydomain,dc=com
objectClass: organization
o: domains

# replicator, mydomain.com
dn: cn=replicator,dc=mydomain,dc=com
objectClass: simpleSecurityObject
objectClass: organizationalRole
objectClass: top
cn: replicator
description: LDAP replicator
userPassword:: <HASH>

# search result
search: 2
result: 0 Success

# numResponses: 4
# numEntries: 3

Here are the important parts of the config files:

/etc/openldap/slapd.conf (master):

...

# Allow users to change their own passwords and mail forwarding addresses.
access to attrs="userPassword,mailForwardingAddress"
    by anonymous    auth
    by self         write
    by dn.exact="cn=vmail,dc=mydomain,dc=com"   read
    by dn.exact="cn=vmailadmin,dc=mydomain,dc=com"  write
    by dn.base="cn=replicator,dc=mydomain,dc=com" read
    by users        none
    by *            break

...

database    bdb
suffix      dc=mydomain,dc=com
checkpoint  128 5
directory   /var/lib/ldap/mydomain.com

rootdn      cn=Manager,dc=mydomain,dc=com
rootpw      <PASSWORD HASH>

sizelimit   1000
cachesize   1000

 ### for LDAP replication
 ###
 moduleload syncprov
 index entryCSN,entryUUID eq
 overlay syncprov
 syncprov-checkpoint 100 10
 syncprov-sessionlog 200

...

/etc/openldap/slapd.conf (slave):

database    bdb
suffix      dc=mydomain,dc=com
rootdn      dc=mydomain,dc=com
directory   /var/lib/ldap/mydomain.com
index       objectclass,entryCSN,entryUUID eq

rootdn      cn=Manager,dc=mydomain,dc=com
rootpw      <PASSWORD HASH>

sizelimit   10000
cachesize   10000

syncrepl rid=101
        provider=ldaps://ldap-master.mydomain.com
        type=RefreshandPersist
        interval=00:01:00:00
        retry="5 5 300 +"
        searchbase="dc=mydomain,dc=com"
        filter="(objectClass=*)"
        scope=sub
        attrs="*,+"
        bindmethod=simple
        tls_cacert=/etc/pki/tls/certs/ldap-master-iRedMail_CA.pem
        binddn="cn=replicator,dc=mydomain,dc=com"
        credentials=<PASSWORD>

Here are the logs.  For simplicity, I've deleted repeating messages.  They all repeat six times before the next message appears.

/var/log/openldap.log (master debug -1):

Feb  2 10:42:20 ldap-master slapd[1948]: => acl_mask: access to entry "mail=tcox@mydomain.com,ou=Aliases,domainName=mydomain.com,o=domains,dc=mydomain,dc=com", attr "entry" requested 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_mask: to all values by "cn=replicator,dc=mydomain,dc=com", (=0)  
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: anonymous 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: self 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: cn=vmail,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: cn=vmailadmin,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: mail=[^,]+@$1,o=domainAdmins,dc=mydomain,dc=com$ 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: mail=[^,]+@$1,ou=Users,domainName=$1,o=domains,dc=mydomain,dc=com$ 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: users 
Feb  2 10:42:20 ldap-master slapd[1948]: <= acl_mask: [7] applying none(=0) (stop) 
Feb  2 10:42:20 ldap-master slapd[1948]: <= acl_mask: [7] mask: none(=0) 
Feb  2 10:42:20 ldap-master slapd[1948]: => access_allowed: read access denied by none(=0) 
Feb  2 10:42:20 ldap-master slapd[1948]: send_search_entry: conn 10884 access to entry (mail=tcox@mydomain.com,ou=Aliases,domainName=mydomain.com,o=domains,dc=mydomain,dc=com) not allowed 
Feb  2 10:42:20 ldap-master slapd[1948]: => access_allowed: search access to "mail=aol@mydomain.com,ou=Aliases,domainName=mydomain.com,o=domains,dc=mydomain,dc=com" "objectClass" requested 
Feb  2 10:42:20 ldap-master slapd[1948]: => dnpat: [1] cn=[^,]+,mail=([^,]+)@([^,]+),ou=Users,domainName=([^,]+),o=domains,dc=mydomain,dc=com$ nsub: 3 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_get: [4] attr objectClass 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_mask: access to entry "mail=aol@mydomain.com,ou=Aliases,domainName=mydomain.com,o=domains,dc=mydomain,dc=com", attr "objectClass" requested 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_mask: to all values by "cn=replicator,dc=mydomain,dc=com", (=0)  
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: anonymous 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: self 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: cn=vmail,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: cn=vmailadmin,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: <= check a_dn_pat: users 
Feb  2 10:42:20 ldap-master slapd[1948]: <= acl_mask: [5] applying read(=rscxd) (stop) 
Feb  2 10:42:20 ldap-master slapd[1948]: <= acl_mask: [5] mask: read(=rscxd) 
Feb  2 10:42:20 ldap-master slapd[1948]: => access_allowed: search access granted by read(=rscxd) 
Feb  2 10:42:20 ldap-master slapd[1948]: => access_allowed: read access to "mail=aol@mydomain.com,ou=Aliases,domainName=mydomain.com,o=domains,dc=mydomain,dc=com" "entry" requested 
Feb  2 10:42:20 ldap-master slapd[1948]: => dnpat: [1] cn=[^,]+,mail=([^,]+)@([^,]+),ou=Users,domainName=([^,]+),o=domains,dc=mydomain,dc=com$ nsub: 3 
Feb  2 10:42:20 ldap-master slapd[1948]: => dn: [7] cn=vmail,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: => dn: [8] cn=vmailadmin,dc=mydomain,dc=com 
Feb  2 10:42:20 ldap-master slapd[1948]: => dnpat: [9] domainName=([^,]+),o=domains,dc=mydomain,dc=com$ nsub: 1 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_get: [9] matched 
Feb  2 10:42:20 ldap-master slapd[1948]: => acl_get: [9] attr entry 
Feb  2 10:42:20 ldap-master slapd[1948]: => match[0]: 33 85 
Feb  2 10:42:20 ldap-master slapd[1948]: d
Feb  2 10:42:20 ldap-master slapd[1948]: o
Feb  2 10:42:20 ldap-master slapd[1948]: m
Feb  2 10:42:20 ldap-master slapd[1948]: a
Feb  2 10:42:20 ldap-master slapd[1948]: i
Feb  2 10:42:20 ldap-master slapd[1948]: n
Feb  2 10:42:20 ldap-master slapd[1948]: N
Feb  2 10:42:20 ldap-master slapd[1948]: a
Feb  2 10:42:20 ldap-master slapd[1948]: m
Feb  2 10:42:20 ldap-master slapd[1948]: e
Feb  2 10:42:20 ldap-master slapd[1948]: =

/var/log/openldap.log (slave debug -1):

Feb  2 10:40:23 ldap-slave slapd[23547]: =>do_syncrepl rid=101
Feb  2 10:40:23 ldap-slave slapd[23547]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb  2 10:40:23 ldap-slave slapd[23547]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb  2 10:40:23 ldap-slave slapd[23547]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Feb  2 10:40:23 ldap-slave slapd[23547]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: =>do_syncrep2 rid=101
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: added 22r listener=(nil)
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: activity on 1 descriptor
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: activity on:
Feb  2 10:40:24 ldap-slave slapd[23547]:
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: activity on 1 descriptor
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: activity on:
Feb  2 10:40:24 ldap-slave slapd[23547]:  22r
Feb  2 10:40:24 ldap-slave slapd[23547]:
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: read active on 22
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Feb  2 10:40:24 ldap-slave slapd[23547]: connection_get(22)
Feb  2 10:40:24 ldap-slave slapd[23547]: connection_get(22): got connid=0
Feb  2 10:40:24 ldap-slave slapd[23547]: =>do_syncrepl rid=101
Feb  2 10:40:24 ldap-slave slapd[23547]: =>do_syncrep2 rid=101
Feb  2 10:40:24 ldap-slave slapd[23547]: do_syncrep2: rid=101 got search entry without Sync State control
Feb  2 10:40:24 ldap-slave slapd[23547]: connection_get(22)
Feb  2 10:40:24 ldap-slave slapd[23547]: connection_get(22): got connid=0
Feb  2 10:40:24 ldap-slave slapd[23547]: daemon: removing 22

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,088

Re: LDAP Replication Fails

Looks like caused by incorrect ACL setting (permission).
Why not use "cn=Manager,dc=mydomain,dc=com" for testing first? So that you can make sure all replication settings are correct, then tune the ACL to make it work with "cn=replicator,dc=mydomain,dc=com" (or use cn=Manager directly).

3 Reply by tedcox

  • tedcox
  • Member
  • Offline
  • Registered: 2012-06-06
  • Posts: 19

Re: LDAP Replication Fails

ZhangHuangbin wrote:

Looks like caused by incorrect ACL setting (permission).
Why not use "cn=Manager,dc=mydomain,dc=com" for testing first? So that you can make sure all replication settings are correct, then tune the ACL to make it work with "cn=replicator,dc=mydomain,dc=com" (or use cn=Manager directly).

Great suggestion.  Sadly, both cn=Manager and cn=vmail fail identically to cn=replicator.  I did try using a hashed password (instead of plain text) for Manager in addition to trying plain text, and that yielded a sasl_bind failure.  So I know it's connecting correctly (since I don't get the bind failure using the plain text passwords).  Other suggestions?

4 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,088

Re: LDAP Replication Fails

- What do you mean cn=Manager fail identically to cn=replicator? You don't need to update ACL in slapd.conf while using cn=Manager, because it has all permissions.
- Make sure you have correct bind dn (cn=Manager) and password in replication setting first.

5 Reply by tedcox (edited by tedcox 2013-02-06 09:59:59)

  • tedcox
  • Member
  • Offline
  • Registered: 2012-06-06
  • Posts: 19

Re: LDAP Replication Fails

Sorry.  I was in a hurry yesterday, and wasn't very clear.

I have made *NO* changes to slapd.conf on the master (or any changes to the master at all).

I edited slapd.conf on the consumer as follows:

binddn="cn=Manager,dc=mydomain,dc=com"
credentials=<Password for Manager>

I restart the service and check the logs:

Feb  5 18:54:00 ldap-slave slapd[15563]: =>do_syncrep2 rid=101
Feb  5 18:54:00 ldap-slave slapd[15563]: do_syncrep2: rid=101 got search entry without Sync State control
Feb  5 18:54:00 ldap-slave slapd[15563]: connection_get(15)
Feb  5 18:54:00 ldap-slave slapd[15563]: connection_get(15): got connid=0
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: removing 15
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: activity on 1 descriptor
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: activity on:
Feb  5 18:54:00 ldap-slave slapd[15563]: 
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: activity on 1 descriptor
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: activity on:
Feb  5 18:54:00 ldap-slave slapd[15563]: 
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Feb  5 18:54:00 ldap-slave slapd[15563]: do_syncrepl: rid=101 rc -1 retrying (4 retries left)

I thought, perhaps, I was mistaken about how the password should be handled, and it was an authentication problem.  So as an experiment, I copied and pasted the hashed LDAP root password from higher up in the slapd.conf.  However, that yields an actual connection failure:

Feb  5 18:48:53 ldap-slave slapd[15401]: =>do_syncrepl rid=101
Feb  5 18:48:53 ldap-slave slapd[15401]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Feb  5 18:48:53 ldap-slave slapd[15401]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Feb  5 18:48:54 ldap-slave slapd[15401]: slap_client_connect: URI=ldaps://mail2.mydomain.com DN="cn=manager,dc=mydomain,dc=com" ldap_sasl_bind_s failed (49)
Feb  5 18:48:54 ldap-slave slapd[15401]: do_syncrepl: rid=101 rc 49 retrying

6 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,088

Re: LDAP Replication Fails

credentials=<Password for Manager>

It must be a plain password.

7 Reply by tedcox (edited by tedcox 2013-02-07 01:24:11)

  • tedcox
  • Member
  • Offline
  • Registered: 2012-06-06
  • Posts: 19

Re: LDAP Replication Fails

ZhangHuangbin wrote:

credentials=<Password for Manager>

It must be a plain password.

Yes.  In the above example I tried both, plain and hashed.  Plain yields exactly the same error as the replicator user.  Just for the sake of clarity, this is the slave log trying to connect to the master using the Manager account with the correct plain text password:

do_syncrep2: rid=101 got search entry without Sync State control