delta syncrepl errors

[Gerard Ranke <gerard.ranke@hku.nl>]

Hello all,

I'm trying to set up delta-syncrepl on a test setup, consisting of a
producer plus consumer running openldap 2.4.45. ( I'll put relevant
parts of both producer and consumer config at the end of this post. )
I'm following the instructions from the openldap manual ( chapter 18.3.2
) as much as possible. Both slapd's start up but replication isn't
happening. I get the following messages in the logs:

producer:
2017-08-18T14:54:39.153754+02:00 pro slapd[10098]: send_search_entry:
conn 1278  ber write failed.
2017-08-18T14:54:44.157627+02:00 pro slapd[10098]: send_search_entry:
conn 1279  ber write failed.
2017-08-18T14:54:49.368758+02:00 pro slapd[10098]: send_search_entry:
conn 1281  ber write failed.
2017-08-18T14:55:09.390341+02:00 pro slapd[10098]: send_search_entry:
conn 1283  ber write failed.
2017-08-18T14:55:19.395091+02:00 pro slapd[10098]: send_search_entry:
conn 1284  ber write failed.

consumer:
2017-08-18T14:54:39.153660+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)
2017-08-18T14:54:39.154089+02:00 del slapd[25530]: do_syncrepl: rid=001
rc -1 retrying (1 retries left)
2017-08-18T14:54:44.157539+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)
2017-08-18T14:54:44.158156+02:00 del slapd[25530]: do_syncrepl: rid=001
rc -1 retrying
2017-08-18T14:54:49.368843+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)
2017-08-18T14:54:49.369446+02:00 del slapd[25530]: do_syncrepl: rid=001
rc -1 retrying
2017-08-18T14:54:59.383750+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)
2017-08-18T14:54:59.384369+02:00 del slapd[25530]: do_syncrepl: rid=001
rc -1 retrying
2017-08-18T14:55:09.390382+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)
2017-08-18T14:55:09.390971+02:00 del slapd[25530]: do_syncrepl: rid=001
rc -1 retrying
2017-08-18T14:55:19.395206+02:00 del slapd[25530]: do_syncrep2: rid=001
got search entry without Sync State control
(reqStart=20170815125023.000001Z,cn=accesslog)

When I do a search on the producer from the consumer I get results that
look like I would expect to see:

ldapsearch -x -h pro.hku.nl -b "cn=accesslog" -D
cn=dsyncuser,dc=hku,dc=nl -w ******
"(&(objectClass=auditWriteObject)(reqResult=0))"
(...)
# 20170817170609.000001Z, accesslog
dn: reqStart=20170817170609.000001Z,cn=accesslog
objectClass: auditAdd
reqStart: 20170817170609.000001Z
reqEnd: 20170817170610.000000Z
reqType: add
reqSession: 1
reqAuthzID: cn=root,dc=hku,dc=nl
reqDN: nlHkuID=77454,ou=People,dc=hku,dc=nl
reqResult: 0
reqMod: objectClass:+ top
reqMod: objectClass:+ posixAccount
reqMod: objectClass:+ shadowAccount
reqMod: objectClass:+ inetOrgPerson
reqMod: objectClass:+ nlHkuPerson
reqMod: objectClass:+ eduPerson
reqMod: objectClass:+ apple-user
reqMod: objectClass:+ sambaSamAccount
reqMod: ou:+ People
reqMod: authAuthority:+ ;basic;
reqMod: nlHkuID:+ 77454
reqMod: loginShell:+ /bin/false
reqMod: gidNumber:+ 300
(...)
reqMod: structuralObjectClass:+ nlHkuPerson
reqMod: entryUUID:+ 1b7405d0-17ba-1037-98e3-99bbae3c2a53
reqMod: creatorsName:+ cn=root,dc=hku,dc=nl
reqMod: createTimestamp:+ 20170817170608Z
reqMod: entryCSN:+ 20170817170608.603041Z#000000#000#000000
reqMod: modifiersName:+ cn=root,dc=hku,dc=nl
reqMod: modifyTimestamp:+ 20170817170608Z
reqEntryUUID: 1b7405d0-17ba-1037-98e3-99bbae3c2a53
(...)

The producer config has:

(...)
dn: cn=module{0},cn=config
objectClass: olcModuleList
cn: module{0}
olcModulePath: /usr/lib64/openldap
olcModuleLoad: {0}back_mdb.so
olcModuleLoad: {1}dynlist.so
olcModuleLoad: {2}accesslog.so
olcModuleLoad: {3}syncprov.so
olcModuleLoad: {4}smbk5pwd.so
structuralObjectClass: olcModuleList
(...)
dn: olcDatabase={1}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {1}mdb
olcDbDirectory: /var/lib/ldap
olcSuffix: dc=hku,dc=nl
olcAccess: {0}to * by dn.base="cn=dsyncuser,dc=hku,dc=nl" read by * break
(...)
olcAccess: {15}to *  by * read
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcLimits: {0}dn.exact="cn=root,dc=hku,dc=nl" size=unlimited time=unlimited
olcLimits: {1}dn.exact="cn=dsyncuser,dc=hku,dc=nl" size=unlimited time=unlim
 ited
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=root,dc=hku,dc=nl
olcRootPW:: ***
olcSyncUseSubentry: FALSE
olcMonitoring: TRUE
(...)
dn: olcOverlay={1}accesslog,olcDatabase={1}mdb,cn=config
objectClass: olcAccessLogConfig
objectClass: olcOverlayConfig
olcOverlay: {1}accesslog
olcAccessLogDB: cn=accesslog
olcAccessLogOps: writes
olcAccessLogPurge: 07+00:00 01+00:00
olcAccessLogSuccess: TRUE
(...)
dn: olcOverlay={2}syncprov,olcDatabase={1}mdb,cn=config
objectClass: olcSyncProvConfig
objectClass: olcOverlayConfig
objectClass: olcConfig
objectClass: top
olcOverlay: {2}syncprov
olcSpCheckpoint: 100 10
olcSpSessionlog: 100
olcSpNoPresent: TRUE
olcSpReloadHint: TRUE
structuralObjectClass: olcSyncProvConfig
(...)

dn: olcDatabase={2}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {2}mdb
olcDbDirectory: /var/lib/ldap-accesslog
olcSuffix: cn=accesslog
olcAccess: {0}to * by dn.base="cn=dsyncuser,dc=hku,dc=nl" read
olcLimits: {0}dn.exact="cn=dsyncuser,dc=hku,dc=nl" size=unlimited time=unlim
 ited
olcRootDN: cn=accesslog
olcDbIndex: default eq
olcDbIndex: entryCSN,objectClass,reqEnd,reqResult,reqStart
olcDbMaxSize: 1047483648
structuralObjectClass: olcMdbConfig
(...)

Parts from the consumer config:

(...)
dn: cn=module{0},cn=config
objectClass: olcModuleList
cn: module{0}
olcModulePath: /usr/lib64/openldap
olcModuleLoad: {0}back_mdb.so
olcModuleLoad: {1}dynlist.so
structuralObjectClass: olcModuleList
(...)
dn: olcDatabase={1}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {1}mdb
olcDbDirectory: /var/lib/ldap
olcSuffix: dc=hku,dc=nl
olcAccess: {0}to * by dn.base="cn=dsyncuser,dc=hku,dc=nl" read by * break
(...)
olcAccess: {15}to *  by * read
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcLimits: {0}dn.exact="cn=root,dc=hku,dc=nl" size=unlimited time=unlimited
olcLimits: {1}dn.exact="cn=dsyncuser,dc=hku,dc=nl" size=unlimited time=unlim
 ited
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=replroot,dc=hku,dc=nl
olcRootPW:: *****
olcSyncUseSubentry: FALSE
olcSyncrepl: {0}rid=001 provider=ldap://pro.hku.nl bindmethod=simple binddn=
 "cn=dsyncuser,dc=hku,dc=nl" credentials="****" tls_cert="/etc/ssl/certs
 /del_cert.pem" tls_key="/etc/ssl/private/del_key.pem" tls_cacertdir="/etc/s
 sl/certs" tls_reqcert=demand tls_crlcheck=none logbase="cn=accesslog" logfi
 lter="(&(objectClass=auditWriteObject)(reqResult=0))" syncdata=accesslog se
 archbase="dc=hku,dc=nl" schemachecking=on type=refreshAndPersist retry="5 5
  10 +"
olcMonitoring: TRUE
olcDbIndex: default pres,eq
olcDbIndex: objectClass eq
olcDbIndex: entryUUID eq
olcDbIndex: entryCSN eq
olcDbIndex: cn eq,sub
(...)
olcDbMaxReaders: 0
olcDbMaxSize: 12147483648
olcDbMode: 0600
olcDbSearchStack: 16
structuralObjectClass: olcMdbConfig


Thank you for taking the time to read all this, any remarks on how to
get this going will be very much appreciated!
Best regards,

gerard