I'm working with a test mirror mode setup on 2.4.7 with db 4.5.20 and seeing issues with SyncRepl. Specifically, do_syncrepl fails with an initial error 0x10 and subsequent 0x14, though at least one modification is propagated. To put another way:
*Systems using same ldif to populate and running nearly identical slapd.conf files (serverID is the only variance).
1) start server 1 2) start server 2 3) add host attribute to posixAccount entry on s-1 4) attribute seen on s-2 but results in the following log 5) no other updates successful until server process restarted.
Mar 4 10:46:14 slapd[22999]: do_syncrep2: rid=001 LDAP_RES_INTERMEDIATE - REFRESH_DELETE Mar 4 10:46:14 slapd[22999]: do_syncrep2: cookie=rid=001,sid=002,csn=20080304164630.523962Z#000000#001#000000 Mar 4 10:46:19 slapd[22999]: conn=0 fd=25 ACCEPT from IP=172.30.24.5:53140 (IP=0.0.0.0:389) Mar 4 10:46:19 slapd[22999]: conn=0 op=0 BIND dn="uid=syncrepl,ou=ldap,dc=example,dc=com" method=128 Mar 4 10:46:19 slapd[22999]: conn=0 op=0 BIND dn="uid=syncrepl,ou=ldap,dc=example,dc=com" mech=SIMPLE ssf=0 Mar 4 10:46:19 slapd[22999]: conn=0 op=0 RESULT tag=97 err=0 text= Mar 4 10:46:19 slapd[22999]: conn=0 op=1 SRCH base="cn=accesslog" scope=2 deref=0 filter="(reqResult=0)" Mar 4 10:46:19 slapd[22999]: conn=0 op=1 SRCH attr=reqDN reqType reqMod reqNewRDN reqDeleteOldRDN reqNewSuperior entryCSN Mar 4 10:46:45 slapd[22999]: conn=1 fd=26 ACCEPT from IP=172.16.71.134:65251 (IP=0.0.0.0:389) Mar 4 10:46:45 slapd[22999]: conn=1 op=0 BIND dn="cn=manager,dc=example,dc=com" method=128 Mar 4 10:46:45 slapd[22999]: conn=1 op=0 BIND dn="cn=manager,dc=example,dc=com" mech=SIMPLE ssf=0 Mar 4 10:46:45 slapd[22999]: conn=1 op=0 RESULT tag=97 err=0 text= Mar 4 10:46:45 slapd[22999]: conn=1 op=1 SRCH base="cn=accesslog" scope=2 deref=0 filter="(objectClass=*)" Mar 4 10:46:45 slapd[22999]: conn=1 op=1 SEARCH RESULT tag=101 err=0 nentries=2 text= Mar 4 10:46:45 slapd[22999]: conn=1 op=2 UNBIND Mar 4 10:46:45 slapd[22999]: conn=1 fd=26 closed Mar 4 10:46:45 slapd[22999]: conn=2 fd=26 ACCEPT from IP=192.168.15.32:45137 (IP=0.0.0.0:389) Mar 4 10:46:45 slapd[22999]: conn=2 fd=26 closed (connection lost) Mar 4 10:47:07 slapd[22999]: do_syncrep2: cookie=rid=001,sid=002,csn=20080304164728.385080Z#000000#001#000000 Mar 4 10:47:07 slapd[22999]: syncrepl_message_to_op: rid=001 be_modify uid=tguy,ou=employees,ou=people,dc=example,dc=com (0) Mar 4 10:47:07 slapd[22999]: null_callback : error code 0x10 Mar 4 10:47:07 slapd[22999]: syncrepl_updateCookie: rid=001 be_modify failed (16) Mar 4 10:47:07 slapd[22999]: do_syncrepl: rid=001 retrying Mar 4 10:47:17 slapd[22999]: null_callback : error code 0x14 Mar 4 10:47:17 slapd[22999]: syncrepl_message_to_op: rid=001 be_modify uid=tguy,ou=employees,ou=people,dc=example,dc=com (20) **** LAST 3 LINES REPEATED THEREAFTER ****
A little more verbose output on the consumer side shows some problem modifying the underlying DB, but I can't see an obvious where to go from here.
Mar 4 10:57:10 slapd[23057]: =>do_syncrepl rid=001 Mar 4 10:57:10 slapd[23057]: =>do_syncrep2 rid=001 Mar 4 10:57:10 slapd[23057]: >>> dnPrettyNormal: <uid=tguy,ou=employees,ou=people,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: <<< dnPrettyNormal: <uid=tguy,ou=employees,ou=people,dc=example,dc=com>, <uid=tguy,ou=employees,ou=people,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: >>> dnPretty: <cn=Manager,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: <<< dnPretty: <cn=Manager,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: >>> dnNormalize: <cn=Manager,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: <<< dnNormalize: <cn=manager,dc=example,dc=com> Mar 4 10:57:10 slapd[23057]: => bdb_entry_get: ndn: "uid=tguy,ou=employees,ou=people,dc=example,dc=com" Mar 4 10:57:10 slapd[23057]: => bdb_entry_get: oc: "(null)", at: "(null)" Mar 4 10:57:10 slapd[23057]: bdb_dn2entry("uid=tguy,ou=employees,ou=people,dc=example,dc=com") Mar 4 10:57:10 slapd[23057]: => bdb_entry_get: found entry: "uid=tguy,ou=employees,ou=people,dc=example,dc=com" Mar 4 10:57:10 slapd[23057]: bdb_entry_get: rc=0 Mar 4 10:57:10 slapd[23057]: hdb_modify: uid=tguy,ou=employees,ou=people,dc=example,dc=com Mar 4 10:57:10 slapd[23057]: bdb_dn2entry("uid=tguy,ou=employees,ou=people,dc=example,dc=com") Mar 4 10:57:10 slapd[23057]: bdb_modify_internal: 0x00000a2b: uid=tguy,ou=employees,ou=people,dc=example,dc=com Mar 4 10:57:10 slapd[23057]: <= acl_access_allowed: granted to database root Mar 4 10:57:10 slapd[23057]: bdb_modify_internal: delete host Mar 4 10:57:10 slapd[23057]: bdb_modify_internal: 16 modify/delete: host: no such value Mar 4 10:57:10 slapd[23057]: hdb_modify: modify failed (16) Mar 4 10:57:10 slapd[23057]: send_ldap_result: conn=-1 op=0 p=0 Mar 4 10:57:10 slapd[23057]: send_ldap_result: err=16 matched="" text="modify/delete: host: no such value" Mar 4 10:57:10 slapd[23057]: null_callback : error code 0x10 Mar 4 10:57:10 slapd[23057]: syncrepl_message_to_op: rid=001 be_modify uid=tguy,ou=employees,ou=people,dc=example,dc=com (16)
Again, if multiple, successful writes are made to the 'primary' server in the mirror, only the first makes it to the 'secondary.' If the second server is restarted, it retrieves all new edits as expected.
Can someone elaborate on what bdb_modify_internal is trying to tell me?
Please let me know if more information is required.
Thanks.
Slapd.conf
# Global Settings #################
include /etc/openldap/schema/core.schema include /etc/openldap/schema/cosine.schema include /etc/openldap/schema/nis.schema include /etc/openldap/schema/inetorgperson.schema include /etc/openldap/schema/sendmail.schema include /etc/openldap/schema/solaris.schema include /etc/openldap/schema/example.schema
pidfile /var/run/openldap/slapd.pid argsfile /var/run/openldap/slapd.args sizelimit unlimited
# Loglevel ##########
loglevel any
moduleload /usr/local/libexec/openldap/back_hdb.la moduleload /usr/local/libexec/openldap/accesslog.la
# TLS/SSL #########
TLSCipherSuite HIGH:MEDIUM:+SSLv2 TLSCertificateFile /etc/openldap/certs/ldap.example.com.crt TLSCertificateKeyFile /etc/openldap/certs/ldap.example.com.key TLSCACertificateFile /etc/openldap/certs/ca.crt TLSVerifyClient never
# Access log ############
database bdb suffix cn=accesslog directory /var/lib/openldap-data/accesslog rootdn cn=Manager,cn=accesslog rootpw secret index default eq index reqStart,objectClass,entryCSN,reqResult eq cachesize 3000 idlcachesize 9000
overlay syncprov syncprov-nopresent TRUE syncprov-reloadhint TRUE
# Primary DB Configuration ##########################
database hdb suffix "dc=example,dc=com" rootdn "cn=Manager,dc=example,dc=com" rootpw secret directory /var/lib/openldap-data/example.com cachesize 3000 idlcachesize 9000
# Primary DB Indexes ####################
index objectClass,entryUUID,entryCSN eq index cn,sn,uid eq,sub,pres,approx index sendmailMTAMapName eq,pres index sendmailMTAMapValue eq index sendmailMTAKey eq,sub,pres index sendmailMTAAliasValue eq,pres index sendmailMTAClassName eq index sendmailMTAClassValue eq index exampleUserModifiable eq
# Primary DB SyncRepl #####################
syncrepl rid=1 provider=ldap://ldap.example.com type=refreshAndPersist searchbase="dc=example,dc=com" bindmethod=simple binddn="uid=syncrepl,ou=ldap,dc=example,dc=com" credentials="syncpw" retry="10 +" schemachecking=off logbase="cn=accesslog" syncdata=accesslog logfilter="(reqResult=0)"
mirrormode on serverID 2
# Primary DB Sync Provider ##########################
overlay syncprov syncprov-checkpoint 10 1 syncprov-sessionlog 100
# Primary DB accesslog ######################
overlay accesslog logdb cn=accesslog logops writes logsuccess TRUE logpurge 07+00:00 01+00:00
# ACLs for Primary DB #####################
access to attrs=userPassword by anonymous auth by self write by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read by dn="uid=pam,ou=ldap,dc=example,dc=com" read by * none
access to dn.subtree="ou=employees,ou=people,dc=example,dc=com" by anonymous auth by self write by dn.regex="uid=[^,]+,ou=employees,ou=people,dc=example,dc=com" read by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read by dn="uid=pam,ou=ldap,dc=example,dc=com" read by * none
access to dn.subtree="ou=group,dc=example,dc=com" by dn.regex="uid=[^,]+,ou=employees,ou=people,dc=example,dc=com" read by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read by dn="uid=pam,ou=ldap,dc=example,dc=com" read
access to dn.subtree="ou=ldap,dc=example,dc=com" by anonymous auth by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read by dn="uid=pam,ou=ldap,dc=example,dc=com" read
access to dn="ou=sendmail,dc=example,dc=com" by ssf=112 dn.base="uid=sendmail,ou=ldap,dc=example,dc=com" read by dn.regex="uid=[^,]+,ou=employees,ou=people,dc=example,dc=com" read by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read
access to dn.subtree="dc=example,dc=com" by dn="uid=syncrepl,ou=ldap,dc=example,dc=com" read by dn="uid=pam,ou=ldap,dc=example,dc=com" read by dn.regex="uid=[^,]+,ou=employees,ou=people,dc=example,dc=com" read
access to dn.base="" by * read